This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: chore: change image repo address
ResultFAILURE
Tests 1 failed / 15 succeeded
Started2020-09-11 12:10
Elapsed1h12m
Revision45184dc5a347cebfa4e7d68c1cc62572220b9693
Refs 527

Test Failures


AzureDisk CSI Driver End-to-End Tests Dynamic Provisioning [single-az] should create a statefulset object, write and read to it, delete the pod and write and read to it again [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] 4m43s

go run hack/e2e.go -v --test --test_args='--ginkgo.focus=AzureDisk\sCSI\sDriver\sEnd\-to\-End\sTests\sDynamic\sProvisioning\s\[single\-az\]\sshould\screate\sa\sstatefulset\sobject\,\swrite\sand\sread\sto\sit\,\sdelete\sthe\spod\sand\swrite\sand\sread\sto\sit\sagain\s\[kubernetes\.io\/azure\-disk\]\s\[disk\.csi\.azure\.com\]\s\[Windows\]$'
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:574
Unexpected error:
    <*errors.errorString | 0xc0002fe020>: {
        s: "Failed to find \"hello world\r\nhello world\r\n\", last result: \"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00hello world\r\n\"",
    }
    Failed to find "hello world
    hello world
    ", last result: "�������������hello world
    "
occurred
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:632
				
				Click to see stdout/stderrfrom junit_01.xml

Filter through log files | View test history on testgrid


Show 15 Passed Tests

Show 23 Skipped Tests

Error lines from build-log.txt

... skipping 60 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11213  100 11213    0     0   121k      0 --:--:-- --:--:-- --:--:--  123k
Downloading https://get.helm.sh/helm-v3.3.1-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull k8sprow.azurecr.io/azuredisk-csi:e2e-9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 || make azuredisk-container push
Error response from daemon: manifest for k8sprow.azurecr.io/azuredisk-csi:e2e-9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 not found: manifest unknown: manifest tagged by "e2e-9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
CGO_ENABLED=0 GOOS=linux go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=e2e-9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2020-09-11T12:22:05Z -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.DriverName=disk.csi.azure.com -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.topologyKey=topology.disk.csi.azure.com/zone -extldflags "-static"" -o _output/azurediskplugin ./pkg/azurediskplugin
CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=e2e-9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=9abcdbf0abf9bb5e758b5c044c38f01816a1a5f5 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2020-09-11T12:23:28Z -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.DriverName=disk.csi.azure.com -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.topologyKey=topology.disk.csi.azure.com/zone -extldflags "-static"" -o _output/azurediskplugin.exe ./pkg/azurediskplugin
docker buildx rm container-builder || true
no builder "container-builder" found
docker buildx create --use --name=container-builder
... skipping 1286 lines ...
Go Version: go1.15
Platform: linux/amd64
Topology Key: N/A

Streaming logs below:
STEP: Building a namespace api object, basename azuredisk
W0911 12:32:36.832523   12436 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 12:32:36.833533   12436 azuredisk.go:110] disable UseInstanceMetadata for controller
I0911 12:32:36.860390   12436 driver.go:80] Enabling controller service capability: CREATE_DELETE_VOLUME
I0911 12:32:36.860432   12436 driver.go:80] Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME
I0911 12:32:36.860437   12436 driver.go:80] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0911 12:32:36.860441   12436 driver.go:80] Enabling controller service capability: LIST_SNAPSHOTS
I0911 12:32:36.860445   12436 driver.go:80] Enabling controller service capability: CLONE_VOLUME
... skipping 21 lines ...
Sep 11 12:32:43.008: INFO: PersistentVolumeClaim pvc-22whm found and phase=Bound (4.162455882s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 12:32:43.183: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-vzl8c" in namespace "azuredisk-8047" to be "Succeeded or Failed"
Sep 11 12:32:43.237: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 53.449588ms
Sep 11 12:32:45.291: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.107658845s
Sep 11 12:32:47.346: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.163034549s
Sep 11 12:32:49.401: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.217357637s
Sep 11 12:32:51.455: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.271827613s
Sep 11 12:32:53.510: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 10.326415851s
... skipping 63 lines ...
Sep 11 12:35:05.020: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2m21.836152198s
Sep 11 12:35:07.073: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2m23.890081988s
Sep 11 12:35:09.129: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2m25.945538122s
Sep 11 12:35:11.184: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2m28.000316161s
Sep 11 12:35:13.239: INFO: Pod "azuredisk-volume-tester-vzl8c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2m30.055133641s
STEP: Saw pod success
Sep 11 12:35:13.239: INFO: Pod "azuredisk-volume-tester-vzl8c" satisfied condition "Succeeded or Failed"
Sep 11 12:35:13.239: INFO: deleting Pod "azuredisk-8047"/"azuredisk-volume-tester-vzl8c"
Sep 11 12:35:13.331: INFO: Pod azuredisk-volume-tester-vzl8c has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-vzl8c in namespace azuredisk-8047
Sep 11 12:35:13.392: INFO: deleting PVC "azuredisk-8047"/"pvc-22whm"
Sep 11 12:35:13.392: INFO: Deleting PersistentVolumeClaim "pvc-22whm"
... skipping 105 lines ...
Sep 11 12:36:03.519: INFO: PersistentVolumeClaim pvc-cxf8s found and phase=Bound (4.163194214s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Sep 11 12:36:03.685: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-dm7js" in namespace "azuredisk-5026" to be "Error status code"
Sep 11 12:36:03.743: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 58.693425ms
Sep 11 12:36:05.798: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113454139s
Sep 11 12:36:07.853: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 4.168571491s
Sep 11 12:36:09.908: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 6.222873149s
Sep 11 12:36:11.962: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 8.277378753s
Sep 11 12:36:14.017: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 10.33210505s
... skipping 37 lines ...
Sep 11 12:37:32.139: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m28.4545703s
Sep 11 12:37:34.198: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m30.51275212s
Sep 11 12:37:36.252: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m32.56760028s
Sep 11 12:37:38.307: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m34.622512492s
Sep 11 12:37:40.362: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m36.676967245s
Sep 11 12:37:42.416: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Pending", Reason="", readiness=false. Elapsed: 1m38.731141625s
Sep 11 12:37:44.471: INFO: Pod "azuredisk-volume-tester-dm7js": Phase="Failed", Reason="", readiness=false. Elapsed: 1m40.785876279s
STEP: Saw pod failure
Sep 11 12:37:44.471: INFO: Pod "azuredisk-volume-tester-dm7js" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 12:37:44.591: INFO: deleting Pod "azuredisk-5026"/"azuredisk-volume-tester-dm7js"
Sep 11 12:37:44.652: INFO: Pod azuredisk-volume-tester-dm7js has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied.
At line:1 char:1
+ echo $null >> C:\mnt\test-1\data
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 360 lines ...
Sep 11 12:45:00.641: INFO: PersistentVolumeClaim pvc-nptjj found and phase=Bound (4.162450323s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 12:45:00.807: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-tsx4w" in namespace "azuredisk-5746" to be "Succeeded or Failed"
Sep 11 12:45:00.883: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 75.650128ms
Sep 11 12:45:02.938: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.130330232s
Sep 11 12:45:04.992: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.184826766s
Sep 11 12:45:07.047: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 6.239216153s
Sep 11 12:45:09.102: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 8.294324849s
Sep 11 12:45:11.156: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 10.348621545s
... skipping 70 lines ...
Sep 11 12:47:37.067: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 2m36.259747193s
Sep 11 12:47:39.122: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 2m38.314285623s
Sep 11 12:47:41.176: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 2m40.369121775s
Sep 11 12:47:43.231: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Pending", Reason="", readiness=false. Elapsed: 2m42.423922129s
Sep 11 12:47:45.286: INFO: Pod "azuredisk-volume-tester-tsx4w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2m44.478258995s
STEP: Saw pod success
Sep 11 12:47:45.286: INFO: Pod "azuredisk-volume-tester-tsx4w" satisfied condition "Succeeded or Failed"
Sep 11 12:47:45.286: INFO: deleting Pod "azuredisk-5746"/"azuredisk-volume-tester-tsx4w"
Sep 11 12:47:45.374: INFO: Pod azuredisk-volume-tester-tsx4w has the following logs: hello world
hello world
hello world

STEP: Deleting pod azuredisk-volume-tester-tsx4w in namespace azuredisk-5746
... skipping 156 lines ...
Sep 11 12:49:33.204: INFO: PersistentVolumeClaim pvc-8k5zl found but phase is Pending instead of Bound.
Sep 11 12:49:35.259: INFO: PersistentVolumeClaim pvc-8k5zl found and phase=Bound (4.162649909s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 12:49:35.433: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kbwtg" in namespace "azuredisk-9002" to be "Succeeded or Failed"
Sep 11 12:49:35.489: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 56.424798ms
Sep 11 12:49:37.544: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.110753152s
Sep 11 12:49:39.598: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164820172s
Sep 11 12:49:41.652: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219394689s
Sep 11 12:49:43.707: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274157343s
Sep 11 12:49:45.762: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329370247s
... skipping 78 lines ...
Sep 11 12:52:28.154: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 2m52.721039522s
Sep 11 12:52:30.208: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 2m54.775695345s
Sep 11 12:52:32.263: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Pending", Reason="", readiness=false. Elapsed: 2m56.830306755s
Sep 11 12:52:34.317: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Running", Reason="", readiness=true. Elapsed: 2m58.884264544s
Sep 11 12:52:36.373: INFO: Pod "azuredisk-volume-tester-kbwtg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 3m0.939719378s
STEP: Saw pod success
Sep 11 12:52:36.373: INFO: Pod "azuredisk-volume-tester-kbwtg" satisfied condition "Succeeded or Failed"
Sep 11 12:52:36.373: INFO: deleting Pod "azuredisk-9002"/"azuredisk-volume-tester-kbwtg"
Sep 11 12:52:36.511: INFO: Pod azuredisk-volume-tester-kbwtg has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-kbwtg in namespace azuredisk-9002
Sep 11 12:52:36.579: INFO: deleting PVC "azuredisk-9002"/"pvc-8k5zl"
Sep 11 12:52:36.579: INFO: Deleting PersistentVolumeClaim "pvc-8k5zl"
... skipping 2351 lines ...
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:01:07 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {default-scheduler } Scheduled: Successfully assigned azuredisk-4535/azuredisk-volume-tester-cq87q-0 to 3727k8s000
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:01:53 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac" 
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:39 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s000} Created: Created container volume-tester
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:39 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s000} Pulled: Container image "e2eteam/busybox:1.29" already present on machine
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:41 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s000} Started: Started container volume-tester
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:48 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s000} Killing: Stopping container volume-tester
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:52 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {attachdetach-controller } FailedAttachVolume: Multi-Attach error for volume "pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac" Volume is already exclusively attached to one node and can't be attached to another
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:02:52 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {default-scheduler } Scheduled: Successfully assigned azuredisk-4535/azuredisk-volume-tester-cq87q-0 to 3727k8s001
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:04:01 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac" 
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:04:55 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s001} FailedMount: Unable to attach or mount volumes: unmounted volumes=[pvc], unattached volumes=[pvc default-token-fwkrb]: timed out waiting for the condition
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:05:20 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s001} Pulled: Container image "e2eteam/busybox:1.29" already present on machine
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:05:20 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s001} Created: Created container volume-tester
Sep 11 13:05:40.709: INFO: At 2020-09-11 13:05:21 +0000 UTC - event for azuredisk-volume-tester-cq87q-0: {kubelet 3727k8s001} Started: Started container volume-tester
... skipping 82 lines ...
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:38
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:41
    should create a statefulset object, write and read to it, delete the pod and write and read to it again [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning_test.go:574

    Unexpected error:
        <*errors.errorString | 0xc0002fe020>: {
            s: "Failed to find \"hello world\r\nhello world\r\n\", last result: \"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00hello world\r\n\"",
        }
        Failed to find "hello world

        hello world
        ", last result: "hello world
        "
    occurred

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:632
... skipping 19 lines ...
Sep 11 13:05:47.048: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-npcct] to have phase Bound
Sep 11 13:05:47.102: INFO: PersistentVolumeClaim pvc-npcct found and phase=Bound (53.826362ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Sep 11 13:05:47.269: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-7mjsv" in namespace "azuredisk-4904" to be "Error status code"
Sep 11 13:05:47.323: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 54.540452ms
Sep 11 13:05:49.378: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109573923s
Sep 11 13:05:51.433: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164385553s
Sep 11 13:05:53.488: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219002488s
Sep 11 13:05:55.570: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.30078361s
Sep 11 13:05:57.625: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.355855498s
... skipping 37 lines ...
Sep 11 13:07:15.731: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m28.46221369s
Sep 11 13:07:17.786: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m30.517011448s
Sep 11 13:07:19.840: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m32.571507864s
Sep 11 13:07:21.895: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m34.626479644s
Sep 11 13:07:23.950: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m36.681418354s
Sep 11 13:07:26.006: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Pending", Reason="", readiness=false. Elapsed: 1m38.736746809s
Sep 11 13:07:28.060: INFO: Pod "azuredisk-volume-tester-7mjsv": Phase="Failed", Reason="", readiness=false. Elapsed: 1m40.790796996s
STEP: Saw pod failure
Sep 11 13:07:28.060: INFO: Pod "azuredisk-volume-tester-7mjsv" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep 11 13:07:28.150: INFO: deleting Pod "azuredisk-4904"/"azuredisk-volume-tester-7mjsv"
Sep 11 13:07:28.212: INFO: Pod azuredisk-volume-tester-7mjsv has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied.
At line:1 char:22
+ ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ...
+                         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 96 lines ...
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:67
    should succeed when creating a shared disk [disk.csi.azure.com][windows]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:138
------------------------------
Pre-Provisioned [single-az] 
  should fail when maxShares is invalid [disk.csi.azure.com][windows]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:157
STEP: Creating a kubernetes client
Sep 11 13:08:14.409: INFO: >>> kubeConfig: /root/tmp248120888/kubeconfig/kubeconfig.westus2.json
STEP: Building a namespace api object, basename azuredisk
STEP: Binding the e2e-test-privileged-psp PodSecurityPolicy to the default service account in azuredisk-1092
STEP: Waiting for a default service account to be provisioned in namespace
... skipping 21 lines ...
Sep 11 13:08:18.556: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-ccd25] to have phase Bound
Sep 11 13:08:18.610: INFO: PersistentVolumeClaim pvc-ccd25 found and phase=Bound (53.958531ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 13:08:18.777: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-97dfh" in namespace "azuredisk-8831" to be "Succeeded or Failed"
Sep 11 13:08:18.835: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 58.231977ms
Sep 11 13:08:20.891: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.113732122s
Sep 11 13:08:22.945: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.168691385s
Sep 11 13:08:25.000: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.223153924s
Sep 11 13:08:27.055: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.278122768s
Sep 11 13:08:29.109: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.332545475s
... skipping 17 lines ...
Sep 11 13:09:06.099: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 47.322529575s
Sep 11 13:09:08.154: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 49.377714654s
Sep 11 13:09:10.210: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 51.432813558s
Sep 11 13:09:12.267: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Pending", Reason="", readiness=false. Elapsed: 53.49045295s
Sep 11 13:09:14.335: INFO: Pod "azuredisk-volume-tester-97dfh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 55.558714539s
STEP: Saw pod success
Sep 11 13:09:14.336: INFO: Pod "azuredisk-volume-tester-97dfh" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
Sep 11 13:09:14.456: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-c7kkb] to have phase Bound
Sep 11 13:09:14.510: INFO: PersistentVolumeClaim pvc-c7kkb found and phase=Bound (54.1567ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 13:09:14.678: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-jxgt9" in namespace "azuredisk-8831" to be "Succeeded or Failed"
Sep 11 13:09:14.736: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 57.722704ms
Sep 11 13:09:16.795: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1170684s
Sep 11 13:09:18.850: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.171675291s
Sep 11 13:09:20.904: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.226106338s
Sep 11 13:09:22.959: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.281035842s
Sep 11 13:09:25.014: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.335637855s
... skipping 19 lines ...
Sep 11 13:10:06.121: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 51.442596664s
Sep 11 13:10:08.175: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 53.497211596s
Sep 11 13:10:10.230: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 55.552163807s
Sep 11 13:10:12.286: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Pending", Reason="", readiness=false. Elapsed: 57.607843288s
Sep 11 13:10:14.341: INFO: Pod "azuredisk-volume-tester-jxgt9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 59.662488238s
STEP: Saw pod success
Sep 11 13:10:14.341: INFO: Pod "azuredisk-volume-tester-jxgt9" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
Sep 11 13:10:14.464: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-mdnls] to have phase Bound
Sep 11 13:10:14.518: INFO: PersistentVolumeClaim pvc-mdnls found and phase=Bound (53.878736ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 13:10:14.686: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ltkt2" in namespace "azuredisk-8831" to be "Succeeded or Failed"
Sep 11 13:10:14.741: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 55.337752ms
Sep 11 13:10:16.812: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126258564s
Sep 11 13:10:18.867: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.180922888s
Sep 11 13:10:20.922: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.236314975s
Sep 11 13:10:22.981: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.295484615s
Sep 11 13:10:25.036: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.350146663s
... skipping 34 lines ...
Sep 11 13:11:36.970: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 1m22.284529398s
Sep 11 13:11:39.025: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 1m24.339606282s
Sep 11 13:11:41.080: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 1m26.39451422s
Sep 11 13:11:43.135: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Pending", Reason="", readiness=false. Elapsed: 1m28.44936722s
Sep 11 13:11:45.190: INFO: Pod "azuredisk-volume-tester-ltkt2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m30.504260809s
STEP: Saw pod success
Sep 11 13:11:45.190: INFO: Pod "azuredisk-volume-tester-ltkt2" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
Sep 11 13:11:45.307: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-gfhsx] to have phase Bound
Sep 11 13:11:45.362: INFO: PersistentVolumeClaim pvc-gfhsx found and phase=Bound (55.115001ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 13:11:45.529: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-c6xnb" in namespace "azuredisk-8831" to be "Succeeded or Failed"
Sep 11 13:11:45.583: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 54.174511ms
Sep 11 13:11:47.637: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.108671661s
Sep 11 13:11:49.693: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164499064s
Sep 11 13:11:51.749: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219789284s
Sep 11 13:11:53.803: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.274661855s
Sep 11 13:11:55.858: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.329238003s
... skipping 7 lines ...
Sep 11 13:12:12.316: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 26.787451865s
Sep 11 13:12:14.371: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 28.842136016s
Sep 11 13:12:16.426: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 30.897460274s
Sep 11 13:12:18.481: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Pending", Reason="", readiness=false. Elapsed: 32.952014811s
Sep 11 13:12:20.536: INFO: Pod "azuredisk-volume-tester-c6xnb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 35.006976061s
STEP: Saw pod success
Sep 11 13:12:20.536: INFO: Pod "azuredisk-volume-tester-c6xnb" satisfied condition "Succeeded or Failed"
STEP: setting up the PV
STEP: creating a PV
STEP: setting up the PVC
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
Sep 11 13:12:20.653: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-v58nw] to have phase Bound
Sep 11 13:12:20.707: INFO: PersistentVolumeClaim pvc-v58nw found and phase=Bound (53.992485ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep 11 13:12:20.878: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-95htp" in namespace "azuredisk-8831" to be "Succeeded or Failed"
Sep 11 13:12:20.932: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 54.305369ms
Sep 11 13:12:22.987: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.109511001s
Sep 11 13:12:25.042: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.164295657s
Sep 11 13:12:27.097: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.219440282s
Sep 11 13:12:29.152: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.273863257s
Sep 11 13:12:31.207: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.3291573s
... skipping 19 lines ...
Sep 11 13:13:12.310: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 51.432189812s
Sep 11 13:13:14.366: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 53.488215548s
Sep 11 13:13:16.421: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 55.543569121s
Sep 11 13:13:18.480: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Pending", Reason="", readiness=false. Elapsed: 57.602701051s
Sep 11 13:13:20.535: INFO: Pod "azuredisk-volume-tester-95htp": Phase="Succeeded", Reason="", readiness=false. Elapsed: 59.657750902s
STEP: Saw pod success
Sep 11 13:13:20.536: INFO: Pod "azuredisk-volume-tester-95htp" satisfied condition "Succeeded or Failed"
Sep 11 13:13:20.536: INFO: deleting Pod "azuredisk-8831"/"azuredisk-volume-tester-95htp"
Sep 11 13:13:20.649: INFO: Pod azuredisk-volume-tester-95htp has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-95htp in namespace azuredisk-8831
Sep 11 13:13:20.711: INFO: deleting PVC "azuredisk-8831"/"pvc-v58nw"
Sep 11 13:13:20.711: INFO: Deleting PersistentVolumeClaim "pvc-v58nw"
... skipping 114 lines ...
Go Version: go1.15
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0911 12:31:53.219684       1 azure.go:50] reading cloud config from secret
W0911 12:31:53.245584       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
I0911 12:31:53.245613       1 azure.go:56] could not read cloud config from secret
I0911 12:31:53.245624       1 azure.go:67] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0911 12:31:53.245661       1 azure.go:77] read cloud config from file: /etc/kubernetes/azure.json successfully
I0911 12:31:53.299811       1 azure_auth.go:232] Using AzurePublicCloud environment
I0911 12:31:53.299885       1 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
I0911 12:31:53.301365       1 azure.go:432] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 90 lines ...
I0911 12:31:54.406164       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0911 12:31:54.406194       1 utils.go:109] GRPC request: {}
I0911 12:31:54.406893       1 controllerserver.go:510] Using default ControllerGetCapabilities
I0911 12:31:54.407017       1 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":2}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":6}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0911 12:32:38.903109       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:32:38.903144       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-1fb32da7-266b-450b-bfb1-f385d1133d70","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["barrier=1","acl"]}},"access_mode":{"mode":1}}]}
I0911 12:32:39.493565       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:32:39.493687       1 controllerserver.go:212] begin to create azure disk(pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:32:39.493742       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-1fb32da7-266b-450b-bfb1-f385d1133d70 StorageAccountType:Standard_LRS Size:10
I0911 12:32:41.854896       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-1fb32da7-266b-450b-bfb1-f385d1133d70 StorageAccountType:Standard_LRS Size:10
I0911 12:32:41.854936       1 controllerserver.go:295] create azure disk(pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:32:41.854980       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Standard_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}}
I0911 12:32:43.343445       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 21 lines ...
I0911 12:34:43.825759       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:34:43.825784       1 utils.go:109] GRPC request: {}
I0911 12:34:43.826669       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:35:13.458408       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:35:13.458437       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:13.459218       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
E0911 12:35:13.537353       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:35:13.826611       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:35:13.826640       1 utils.go:109] GRPC request: {}
I0911 12:35:13.827490       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:35:14.546364       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:35:14.546420       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:14.547093       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
E0911 12:35:14.571193       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:35:16.578724       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:35:16.578752       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:16.579586       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
E0911 12:35:16.600911       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:35:17.285168       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:35:17.285312       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:17.286907       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70 from node 3727k8s000
I0911 12:35:17.418675       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70 from node "3727k8s000"
I0911 12:35:17.418744       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-1fb32da7-266b-450b-bfb1-f385d1133d70" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"
I0911 12:35:17.418765       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-1fb32da7-266b-450b-bfb1-f385d1133d70, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
I0911 12:35:20.609834       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:35:20.609973       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:20.610604       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
E0911 12:35:20.610626       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) since it's in attaching or detaching state
I0911 12:35:28.628340       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:35:28.628375       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70"}
I0911 12:35:28.629095       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
E0911 12:35:28.629204       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) since it's in attaching or detaching state
I0911 12:35:32.858908       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-1fb32da7-266b-450b-bfb1-f385d1133d70, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) returned with <nil>
I0911 12:35:32.858959       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-1fb32da7-266b-450b-bfb1-f385d1133d70, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) succeeded
I0911 12:35:32.858972       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70 from node 3727k8s000 successfully
I0911 12:35:32.858993       1 utils.go:114] GRPC response: {}
I0911 12:35:43.825582       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:35:43.825694       1 utils.go:109] GRPC request: {}
... skipping 3 lines ...
I0911 12:35:44.638594       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70)
I0911 12:35:49.779826       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70
I0911 12:35:49.779874       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70) successfully
I0911 12:35:49.779886       1 utils.go:114] GRPC response: {}
I0911 12:35:59.348487       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:35:59.348513       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-6006f77d-5693-46e9-b843-7d333c2b4667","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:35:59.372353       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:35:59.373005       1 controllerserver.go:212] begin to create azure disk(pvc-6006f77d-5693-46e9-b843-7d333c2b4667) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:35:59.373132       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-6006f77d-5693-46e9-b843-7d333c2b4667 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:36:01.723810       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-6006f77d-5693-46e9-b843-7d333c2b4667 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:36:01.723946       1 controllerserver.go:295] create azure disk(pvc-6006f77d-5693-46e9-b843-7d333c2b4667) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:36:01.724005       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}}
I0911 12:36:03.716543       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 18 lines ...
I0911 12:37:43.826092       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:37:43.826113       1 utils.go:109] GRPC request: {}
I0911 12:37:43.826861       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:37:44.779863       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:37:44.779891       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:44.780752       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
E0911 12:37:44.840335       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:37:45.847929       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:37:45.847954       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:45.848892       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
E0911 12:37:45.868436       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:37:47.442581       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:37:47.442606       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:47.443547       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667 from node 3727k8s000
I0911 12:37:47.504776       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667 from node "3727k8s000"
I0911 12:37:47.504840       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-6006f77d-5693-46e9-b843-7d333c2b4667" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"
I0911 12:37:47.504857       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-6006f77d-5693-46e9-b843-7d333c2b4667, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
I0911 12:37:47.880147       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:37:47.880172       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:47.880970       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
E0911 12:37:47.880991       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) since it's in attaching or detaching state
I0911 12:37:51.908825       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:37:51.908859       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:51.909795       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
E0911 12:37:51.909820       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) since it's in attaching or detaching state
I0911 12:37:59.919948       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:37:59.920134       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667"}
I0911 12:37:59.920790       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
E0911 12:37:59.920912       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) since it's in attaching or detaching state
I0911 12:38:02.940717       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-6006f77d-5693-46e9-b843-7d333c2b4667, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) returned with <nil>
I0911 12:38:02.940765       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-6006f77d-5693-46e9-b843-7d333c2b4667, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) succeeded
I0911 12:38:02.940991       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667 from node 3727k8s000 successfully
I0911 12:38:02.941076       1 utils.go:114] GRPC response: {}
I0911 12:38:13.825778       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:38:13.825825       1 utils.go:109] GRPC request: {}
... skipping 3 lines ...
I0911 12:38:15.930208       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667)
I0911 12:38:21.101812       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667
I0911 12:38:21.101853       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-6006f77d-5693-46e9-b843-7d333c2b4667) successfully
I0911 12:38:21.101867       1 utils.go:114] GRPC response: {}
I0911 12:38:27.301199       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:38:27.301229       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:38:27.323592       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:38:27.323647       1 controllerserver.go:212] begin to create azure disk(pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:38:27.323665       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac StorageAccountType:Premium_LRS Size:10
I0911 12:38:29.680696       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac StorageAccountType:Premium_LRS Size:10
I0911 12:38:29.680735       1 controllerserver.go:295] create azure disk(pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:38:29.680750       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Premium_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}}
I0911 12:38:31.609448       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 11 lines ...
I0911 12:38:47.221848       1 utils.go:114] GRPC response: {"publish_context":{"LUN":"0"}}
I0911 12:39:13.828273       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:39:13.828301       1 utils.go:109] GRPC request: {}
I0911 12:39:13.829338       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:39:23.790802       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:39:23.790826       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-cd496550-1ff0-4648-89f0-4bfa632be491","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:39:23.828573       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:39:23.828751       1 controllerserver.go:212] begin to create azure disk(pvc-cd496550-1ff0-4648-89f0-4bfa632be491) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:39:23.828901       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-cd496550-1ff0-4648-89f0-4bfa632be491 StorageAccountType:Premium_LRS Size:10
I0911 12:39:26.207533       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-cd496550-1ff0-4648-89f0-4bfa632be491 StorageAccountType:Premium_LRS Size:10
I0911 12:39:26.207571       1 controllerserver.go:295] create azure disk(pvc-cd496550-1ff0-4648-89f0-4bfa632be491) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:39:26.207585       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Premium_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}}
I0911 12:39:28.157180       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 17 lines ...
I0911 12:39:43.826544       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:40:13.826077       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:40:13.826109       1 utils.go:109] GRPC request: {}
I0911 12:40:13.827014       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:40:22.350908       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:40:22.351008       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:40:22.374195       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:40:22.374469       1 controllerserver.go:212] begin to create azure disk(pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:40:22.374519       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb StorageAccountType:Premium_LRS Size:10
I0911 12:40:24.700296       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb StorageAccountType:Premium_LRS Size:10
I0911 12:40:24.700340       1 controllerserver.go:295] create azure disk(pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:40:24.700358       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Premium_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}}
I0911 12:40:26.705144       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 18 lines ...
I0911 12:42:13.825903       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:42:13.825928       1 utils.go:109] GRPC request: {}
I0911 12:42:13.826782       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:42:16.790162       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:42:16.790359       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:16.791389       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
E0911 12:42:16.850576       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:42:17.909630       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:42:17.909824       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:17.911411       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
E0911 12:42:17.934348       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:42:19.464738       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:42:19.465037       1 utils.go:109] GRPC request: {"node_id":"3727k8s001","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:19.466557       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb from node 3727k8s001
I0911 12:42:19.622962       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb from node "3727k8s001"
I0911 12:42:19.623013       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"
I0911 12:42:19.623034       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
I0911 12:42:19.942616       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:42:19.942730       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:19.943785       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
E0911 12:42:19.943851       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) since it's in attaching or detaching state
I0911 12:42:23.952156       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:42:23.952369       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:23.953436       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
E0911 12:42:23.953483       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) since it's in attaching or detaching state
I0911 12:42:31.961866       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:42:31.961901       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb"}
I0911 12:42:31.962750       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb)
E0911 12:42:31.962863       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) since it's in attaching or detaching state
I0911 12:42:39.995273       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) returned with <nil>
I0911 12:42:39.995399       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) succeeded
I0911 12:42:39.995468       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb from node 3727k8s001 successfully
I0911 12:42:39.995507       1 utils.go:114] GRPC response: {}
I0911 12:42:43.826027       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:42:43.826054       1 utils.go:109] GRPC request: {}
... skipping 4 lines ...
I0911 12:42:53.102838       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb
I0911 12:42:53.102871       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7382887e-c0bc-4388-9c16-167d96f1e3fb) successfully
I0911 12:42:53.102911       1 utils.go:114] GRPC response: {}
I0911 12:43:00.172562       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:00.172590       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:00.173328       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
E0911 12:43:00.194278       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:01.206109       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:01.206135       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:01.207109       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
E0911 12:43:01.229024       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:03.236299       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:03.236331       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:03.237536       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
E0911 12:43:03.259575       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:07.268391       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:07.268418       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:07.270003       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
E0911 12:43:07.291054       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:08.497355       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:43:08.497402       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:08.498449       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491 from node 3727k8s000
I0911 12:43:08.498516       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491 from node "3727k8s000"
I0911 12:43:08.530898       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-cd496550-1ff0-4648-89f0-4bfa632be491" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"
I0911 12:43:08.530951       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-cd496550-1ff0-4648-89f0-4bfa632be491, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
I0911 12:43:13.825460       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:43:13.825487       1 utils.go:109] GRPC request: {}
I0911 12:43:13.826169       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:43:15.300046       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:15.300070       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:15.301068       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
E0911 12:43:15.301092       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) since it's in attaching or detaching state
I0911 12:43:18.906887       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-cd496550-1ff0-4648-89f0-4bfa632be491, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) returned with <nil>
I0911 12:43:18.906957       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-cd496550-1ff0-4648-89f0-4bfa632be491, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) succeeded
I0911 12:43:18.906989       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491 from node 3727k8s000 successfully
I0911 12:43:18.907043       1 utils.go:114] GRPC response: {}
I0911 12:43:31.308365       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:31.308389       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:43:31.309188       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491)
I0911 12:43:36.461744       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491
I0911 12:43:36.461791       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491) successfully
I0911 12:43:36.461803       1 utils.go:114] GRPC response: {}
I0911 12:43:41.914681       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:41.914862       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:41.915969       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
E0911 12:43:41.937636       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:42.946212       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:42.946243       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:42.948725       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
E0911 12:43:42.971785       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:43.825641       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:43:43.825670       1 utils.go:109] GRPC request: {}
I0911 12:43:43.826503       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:43:44.986904       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:44.987081       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:44.988301       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
E0911 12:43:45.007543       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:43:48.530507       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:43:48.530607       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:48.531614       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac from node 3727k8s000
I0911 12:43:48.569186       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac from node "3727k8s000"
I0911 12:43:48.569511       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"
I0911 12:43:48.569716       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
I0911 12:43:49.015244       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:49.015273       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:49.015970       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
E0911 12:43:49.016006       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) since it's in attaching or detaching state
I0911 12:43:57.022818       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:43:57.022844       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:57.024071       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac)
E0911 12:43:57.024184       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) since it's in attaching or detaching state
I0911 12:44:03.912099       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) returned with <nil>
I0911 12:44:03.912142       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac) succeeded
I0911 12:44:03.912155       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac from node 3727k8s000 successfully
I0911 12:44:03.912170       1 utils.go:114] GRPC response: {}
I0911 12:44:13.035122       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:44:13.035273       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
... skipping 3 lines ...
I0911 12:44:13.317451       1 utils.go:114] GRPC response: {}
I0911 12:44:13.825923       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:44:13.825949       1 utils.go:109] GRPC request: {}
I0911 12:44:13.826725       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:44:22.301740       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:44:22.301787       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:44:22.327371       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:44:22.327582       1 controllerserver.go:212] begin to create azure disk(pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:44:22.327607       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:24.601573       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:24.601691       1 controllerserver.go:295] create azure disk(pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:44:24.601742       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a"}}
I0911 12:44:26.554678       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:44:26.554705       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a"}
I0911 12:44:26.555557       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a)
I0911 12:44:26.788519       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a
I0911 12:44:26.788558       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-c2b8502f-3378-4bb9-9bd9-2e01963d724a) successfully
I0911 12:44:26.788571       1 utils.go:114] GRPC response: {}
I0911 12:44:33.569447       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:44:33.569481       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:44:33.592951       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:44:33.593004       1 controllerserver.go:212] begin to create azure disk(pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:44:33.593024       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:35.845481       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:35.845530       1 controllerserver.go:295] create azure disk(pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:44:35.845547       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5e53bef0-c929-4d1e-b6a3-482f295aeaf3"}}
I0911 12:44:43.825709       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:44:43.825841       1 utils.go:109] GRPC request: {}
I0911 12:44:43.826572       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:44:47.704332       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:44:47.704543       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-5cb01450-53ad-4817-9f88-77bcd3887571","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:44:47.729255       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:44:47.729344       1 controllerserver.go:212] begin to create azure disk(pvc-5cb01450-53ad-4817-9f88-77bcd3887571) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:44:47.729459       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-5cb01450-53ad-4817-9f88-77bcd3887571 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:50.071554       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-5cb01450-53ad-4817-9f88-77bcd3887571 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:50.071598       1 controllerserver.go:295] create azure disk(pvc-5cb01450-53ad-4817-9f88-77bcd3887571) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:44:50.071614       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571"}}
I0911 12:44:52.101555       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:44:52.101589       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-05326442-f2f6-4f58-ab0a-16f01d907219","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:44:52.123454       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:44:52.123509       1 controllerserver.go:212] begin to create azure disk(pvc-05326442-f2f6-4f58-ab0a-16f01d907219) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:44:52.123530       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-05326442-f2f6-4f58-ab0a-16f01d907219 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:54.336277       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-05326442-f2f6-4f58-ab0a-16f01d907219 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:54.336362       1 controllerserver.go:295] create azure disk(pvc-05326442-f2f6-4f58-ab0a-16f01d907219) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:44:54.336385       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219"}}
I0911 12:44:56.469552       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:44:56.469651       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:44:56.496343       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:44:56.496611       1 controllerserver.go:212] begin to create azure disk(pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:44:56.496662       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:58.730083       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6 StorageAccountType:StandardSSD_LRS Size:10
I0911 12:44:58.730159       1 controllerserver.go:295] create azure disk(pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:44:58.730204       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}}
I0911 12:45:01.002041       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 56 lines ...
I0911 12:47:43.825954       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:47:43.825995       1 utils.go:109] GRPC request: {}
I0911 12:47:43.827262       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:47:45.506268       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:47:45.506298       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:47:45.507189       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:47:45.630753       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:47:46.639213       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:47:46.639241       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:47:46.640162       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:47:46.661987       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:47:48.670231       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:47:48.670441       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:47:48.671176       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:47:48.691430       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:47:48.874150       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:47:48.874253       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571"}
I0911 12:47:48.875043       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571 from node 3727k8s000
I0911 12:47:48.875138       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571 from node "3727k8s000"
I0911 12:47:48.886568       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:47:48.886588       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219"}
... skipping 5 lines ...
I0911 12:47:48.974590       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-5cb01450-53ad-4817-9f88-77bcd3887571, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571)
I0911 12:47:48.974842       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219 from node "3727k8s000"
I0911 12:47:48.976498       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6 from node "3727k8s000"
I0911 12:47:52.698911       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:47:52.698979       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:47:52.700206       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:47:52.719882       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:47:59.514231       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-5cb01450-53ad-4817-9f88-77bcd3887571, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571) returned with <nil>
I0911 12:47:59.514290       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-5cb01450-53ad-4817-9f88-77bcd3887571, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571) succeeded
I0911 12:47:59.514303       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571 from node 3727k8s000 successfully
I0911 12:47:59.514318       1 utils.go:114] GRPC response: {}
I0911 12:47:59.597099       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-05326442-f2f6-4f58-ab0a-16f01d907219" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219"
I0911 12:47:59.597136       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-05326442-f2f6-4f58-ab0a-16f01d907219, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219)
I0911 12:48:00.726988       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:48:00.727018       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:48:00.727938       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:48:00.769535       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s000), could not be deleted
I0911 12:48:13.826082       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:48:13.826106       1 utils.go:109] GRPC request: {}
I0911 12:48:13.827038       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:48:14.964979       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-05326442-f2f6-4f58-ab0a-16f01d907219, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219) returned with <nil>
I0911 12:48:14.965026       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-05326442-f2f6-4f58-ab0a-16f01d907219, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219) succeeded
I0911 12:48:14.965038       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219 from node 3727k8s000 successfully
I0911 12:48:14.965055       1 utils.go:114] GRPC response: {}
I0911 12:48:14.999101       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"
I0911 12:48:14.999711       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
I0911 12:48:16.778799       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:48:16.778832       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6"}
I0911 12:48:16.780114       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6)
E0911 12:48:16.780237       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) since it's in attaching or detaching state
I0911 12:48:30.326765       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - detach disk(pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) returned with <nil>
I0911 12:48:30.326817       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6) succeeded
I0911 12:48:30.326839       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0782b83d-c51c-4aee-b076-aea22c39f6c6 from node 3727k8s000 successfully
I0911 12:48:30.326854       1 utils.go:114] GRPC response: {}
I0911 12:48:43.825881       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:48:43.826153       1 utils.go:109] GRPC request: {}
... skipping 18 lines ...
I0911 12:49:12.026764       1 utils.go:114] GRPC response: {}
I0911 12:49:13.825925       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:49:13.826012       1 utils.go:109] GRPC request: {}
I0911 12:49:13.826843       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:49:22.308595       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:49:22.308624       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-67d73f28-173f-4bf9-96b0-07e7a20245da","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:49:22.334112       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:49:22.334247       1 controllerserver.go:212] begin to create azure disk(pvc-67d73f28-173f-4bf9-96b0-07e7a20245da) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:49:22.334462       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-67d73f28-173f-4bf9-96b0-07e7a20245da StorageAccountType:Standard_LRS Size:10
I0911 12:49:24.627892       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-67d73f28-173f-4bf9-96b0-07e7a20245da StorageAccountType:Standard_LRS Size:10
I0911 12:49:24.627936       1 controllerserver.go:295] create azure disk(pvc-67d73f28-173f-4bf9-96b0-07e7a20245da) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:49:24.627952       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Standard_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da"}}
I0911 12:49:26.700630       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:49:26.700654       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce","parameters":{"skuName":"Premium_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:49:26.722500       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:49:26.722553       1 controllerserver.go:212] begin to create azure disk(pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:49:26.722730       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce StorageAccountType:Premium_LRS Size:10
I0911 12:49:28.955088       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce StorageAccountType:Premium_LRS Size:10
I0911 12:49:28.955277       1 controllerserver.go:295] create azure disk(pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce) account type(Premium_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:49:28.955405       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Premium_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce"}}
I0911 12:49:31.082308       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:49:31.082334       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-e03d5227-a714-4c6b-a601-8ab3392b901a","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:49:31.106213       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:49:31.106283       1 controllerserver.go:212] begin to create azure disk(pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:49:31.106302       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-e03d5227-a714-4c6b-a601-8ab3392b901a StorageAccountType:StandardSSD_LRS Size:10
I0911 12:49:33.320245       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-e03d5227-a714-4c6b-a601-8ab3392b901a StorageAccountType:StandardSSD_LRS Size:10
I0911 12:49:33.320291       1 controllerserver.go:295] create azure disk(pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:49:33.320307       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}}
I0911 12:49:35.519033       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 44 lines ...
I0911 12:52:13.825638       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:52:13.825661       1 utils.go:109] GRPC request: {}
I0911 12:52:13.827605       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:52:36.651283       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:52:36.651384       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:36.652007       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:52:36.726557       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:52:37.734202       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:52:37.734236       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:37.735177       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:52:37.754669       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:52:39.763022       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:52:39.763057       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:39.763915       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:52:39.783863       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:52:40.206309       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:52:40.206341       1 utils.go:109] GRPC request: {"node_id":"3727k8s001","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da"}
I0911 12:52:40.209311       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da from node 3727k8s001
I0911 12:52:40.209671       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:52:40.209693       1 utils.go:109] GRPC request: {"node_id":"3727k8s001","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:40.215181       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a from node 3727k8s001
... skipping 5 lines ...
I0911 12:52:40.279454       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-67d73f28-173f-4bf9-96b0-07e7a20245da, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da)
I0911 12:52:40.279683       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a from node "3727k8s001"
I0911 12:52:40.279868       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce from node "3727k8s001"
I0911 12:52:43.792072       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:52:43.792104       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:43.793004       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:52:43.814133       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:52:43.825808       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:52:43.825947       1 utils.go:109] GRPC request: {}
I0911 12:52:43.827698       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:52:51.822514       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:52:51.822544       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:52:51.823576       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:52:51.850890       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:52:55.817305       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-67d73f28-173f-4bf9-96b0-07e7a20245da, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da) returned with <nil>
I0911 12:52:55.817387       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-67d73f28-173f-4bf9-96b0-07e7a20245da, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da) succeeded
I0911 12:52:55.817403       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da from node 3727k8s001 successfully
I0911 12:52:55.817645       1 utils.go:114] GRPC response: {}
I0911 12:52:55.848966       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-e03d5227-a714-4c6b-a601-8ab3392b901a" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"
I0911 12:52:55.848999       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-e03d5227-a714-4c6b-a601-8ab3392b901a, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
I0911 12:53:07.861769       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:53:07.861798       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a"}
I0911 12:53:07.864074       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a)
E0911 12:53:07.864275       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) since it's in attaching or detaching state
I0911 12:53:11.272855       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-e03d5227-a714-4c6b-a601-8ab3392b901a, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) returned with <nil>
I0911 12:53:11.272932       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-e03d5227-a714-4c6b-a601-8ab3392b901a, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a) succeeded
I0911 12:53:11.273347       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a from node 3727k8s001 successfully
I0911 12:53:11.273385       1 utils.go:114] GRPC response: {}
I0911 12:53:11.305723       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce"
I0911 12:53:11.305755       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce)
... skipping 24 lines ...
I0911 12:53:57.978530       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da)
I0911 12:54:03.113116       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da
I0911 12:54:03.113222       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-67d73f28-173f-4bf9-96b0-07e7a20245da) successfully
I0911 12:54:03.113259       1 utils.go:114] GRPC response: {}
I0911 12:54:10.082666       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:54:10.082705       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 12:54:10.104755       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:54:10.104971       1 controllerserver.go:212] begin to create azure disk(pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:54:10.105001       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125 StorageAccountType:Standard_LRS Size:10
I0911 12:54:12.352931       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125 StorageAccountType:Standard_LRS Size:10
I0911 12:54:12.353776       1 controllerserver.go:295] create azure disk(pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:54:12.353881       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Standard_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125"}}
I0911 12:54:13.828495       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
... skipping 14 lines ...
I0911 12:54:45.057537       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125)
I0911 12:54:50.235645       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125
I0911 12:54:50.235680       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-8b7d67d0-481d-40c1-aad3-07dd1d80c125) successfully
I0911 12:54:50.235696       1 utils.go:114] GRPC response: {}
I0911 12:54:57.486438       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:54:57.486469       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b","parameters":{"skuName":"Standard_LRS","tags":"disk=test"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["barrier=1","acl"]}},"access_mode":{"mode":1}}]}
I0911 12:54:57.507582       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:54:57.507646       1 controllerserver.go:212] begin to create azure disk(pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:54:57.507666       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b StorageAccountType:Standard_LRS Size:10
I0911 12:54:59.757685       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b StorageAccountType:Standard_LRS Size:10
I0911 12:54:59.757804       1 controllerserver.go:295] create azure disk(pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:54:59.757875       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Standard_LRS","tags":"disk=test"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}}
I0911 12:55:01.893848       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 18 lines ...
I0911 12:56:43.825954       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:56:43.825982       1 utils.go:109] GRPC request: {}
I0911 12:56:43.826947       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:56:49.269886       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:56:49.269985       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:56:49.270615       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
E0911 12:56:49.338485       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:56:50.350557       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:56:50.350596       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:56:50.351705       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
E0911 12:56:50.372619       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 12:56:50.474476       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 12:56:50.474605       1 utils.go:109] GRPC request: {"node_id":"3727k8s001","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:56:50.475851       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b from node 3727k8s001
I0911 12:56:50.532000       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b from node "3727k8s001"
I0911 12:56:50.532078       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"
I0911 12:56:50.532097       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
I0911 12:56:52.380569       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:56:52.380688       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:56:52.381408       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
E0911 12:56:52.381429       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) since it's in attaching or detaching state
I0911 12:56:56.389496       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:56:56.389524       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:56:56.390358       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
E0911 12:56:56.390526       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) since it's in attaching or detaching state
I0911 12:57:04.398571       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 12:57:04.398595       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b"}
I0911 12:57:04.399446       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
E0911 12:57:04.399472       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) since it's in attaching or detaching state
I0911 12:57:05.949813       1 azure_controller_standard.go:180] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) returned with <nil>
I0911 12:57:05.949868       1 azure_controller_common.go:242] azureDisk - detach disk(pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) succeeded
I0911 12:57:05.949881       1 controllerserver.go:479] detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b from node 3727k8s001 successfully
I0911 12:57:05.949895       1 utils.go:114] GRPC response: {}
I0911 12:57:13.825532       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:57:13.825556       1 utils.go:109] GRPC request: {}
... skipping 3 lines ...
I0911 12:57:20.408278       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b)
I0911 12:57:25.596388       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b
I0911 12:57:25.596483       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-0f6cff60-329d-4fe4-8f81-6a4fa0f2914b) successfully
I0911 12:57:25.596512       1 utils.go:114] GRPC response: {}
I0911 12:57:32.299891       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 12:57:32.300536       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-9620c6fa-0dcd-448a-976b-70defce08559","parameters":{"skuName":"Standard_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["barrier=1","acl"]}},"access_mode":{"mode":1}}]}
I0911 12:57:32.325428       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 12:57:32.325490       1 controllerserver.go:212] begin to create azure disk(pvc-9620c6fa-0dcd-448a-976b-70defce08559) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 12:57:32.325651       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-9620c6fa-0dcd-448a-976b-70defce08559 StorageAccountType:Standard_LRS Size:10
I0911 12:57:34.555346       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-9620c6fa-0dcd-448a-976b-70defce08559 StorageAccountType:Standard_LRS Size:10
I0911 12:57:34.555388       1 controllerserver.go:295] create azure disk(pvc-9620c6fa-0dcd-448a-976b-70defce08559) account type(Standard_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 12:57:34.555403       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"Standard_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559"}}
I0911 12:57:36.615992       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 42 lines ...
I0911 13:00:48.241895       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559)
I0911 13:00:53.529505       1 azure_managedDiskController.go:244] azureDisk - deleted a managed disk: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559
I0911 13:00:53.529552       1 controllerserver.go:353] delete azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-9620c6fa-0dcd-448a-976b-70defce08559) successfully
I0911 13:00:53.529569       1 utils.go:114] GRPC response: {}
I0911 13:01:00.402153       1 utils.go:108] GRPC call: /csi.v1.Controller/CreateVolume
I0911 13:01:00.402342       1 utils.go:109] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"requisite":[{"segments":{"topology.disk.csi.azure.com/zone":""}}]},"capacity_range":{"required_bytes":10737418240},"name":"pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac","parameters":{"skuName":"StandardSSD_LRS"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
I0911 13:01:00.425656       1 azure_diskclient.go:124] Received error in disk.get.request: resourceID: /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac, error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {"error":{"code":"ResourceNotFound","message":"The Resource 'Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac' under resource group 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10' was not found. For more details please go to https://aka.ms/ARMResourceNotFoundFix"}}
I0911 13:01:00.425707       1 controllerserver.go:212] begin to create azure disk(pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) selectedAvailabilityZone() maxShares(0)
I0911 13:01:00.425729       1 azure_managedDiskController.go:85] azureDisk - creating new managed Name:pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac StorageAccountType:StandardSSD_LRS Size:10
I0911 13:01:02.841405       1 azure_managedDiskController.go:207] azureDisk - created new MD Name:pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac StorageAccountType:StandardSSD_LRS Size:10
I0911 13:01:02.841448       1 controllerserver.go:295] create azure disk(pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) account type(StandardSSD_LRS) rg(kubetest-c7e03562-f427-11ea-9108-8e979541ec10) location() size(10) successfully
I0911 13:01:02.841463       1 utils.go:114] GRPC response: {"volume":{"accessible_topology":[{"segments":{"topology.disk.csi.azure.com/zone":""}}],"capacity_bytes":10737418240,"content_source":{"Type":null},"volume_context":{"skuName":"StandardSSD_LRS"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}}
I0911 13:01:07.505283       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
... skipping 62 lines ...
I0911 13:05:47.712892       1 controllerserver.go:419] Trying to attach volume "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly" to node "3727k8s000"
I0911 13:05:47.735595       1 azure_controller_common.go:183] Trying to attach volume "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly" lun 0 to node "3727k8s000".
I0911 13:05:47.735660       1 azure_controller_standard.go:93] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - attach disk(pre-provisioned-readOnly, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly) with DiskEncryptionSetID()
I0911 13:05:47.747573       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:05:47.747596       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:05:47.748521       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:05:47.766907       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 13:05:48.776158       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:05:48.776277       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:05:48.776890       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:05:48.802819       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 13:05:50.821997       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:05:50.822077       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:05:50.823008       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:05:50.841029       1 utils.go:112] GRPC error: disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) already attached to node(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/virtualMachines/3727k8s001), could not be deleted
I0911 13:05:50.882169       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I0911 13:05:50.882408       1 utils.go:109] GRPC request: {"node_id":"3727k8s001","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:05:50.883164       1 controllerserver.go:470] Trying to detach volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac from node 3727k8s001
I0911 13:05:51.007299       1 azure_controller_common.go:208] detach /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac from node "3727k8s001"
I0911 13:05:51.007523       1 azure_controller_standard.go:143] azureDisk - detach disk: name "pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac" uri "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"
I0911 13:05:51.007684       1 azure_controller_standard.go:162] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s001) - detach disk(pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
I0911 13:05:54.854587       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:05:54.854620       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:05:54.855378       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:05:54.855426       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) since it's in attaching or detaching state
I0911 13:06:02.864107       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:06:02.864139       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:06:02.865013       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:06:02.865056       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) since it's in attaching or detaching state
I0911 13:06:13.825927       1 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 13:06:13.825953       1 utils.go:109] GRPC request: {}
I0911 13:06:13.828148       1 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 13:06:18.871995       1 utils.go:108] GRPC call: /csi.v1.Controller/DeleteVolume
I0911 13:06:18.872019       1 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac"}
I0911 13:06:18.872985       1 controllerserver.go:343] deleting azure disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac)
E0911 13:06:18.873051       1 utils.go:112] GRPC error: failed to delete disk(/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-7843421b-8bd4-49c6-9860-785e8a0d11ac) since it's in attaching or detaching state
I0911 13:06:28.407024       1 azure_controller_standard.go:111] azureDisk - update(kubetest-c7e03562-f427-11ea-9108-8e979541ec10): vm(3727k8s000) - attach disk(pre-provisioned-readOnly, /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly) returned with <nil>
I0911 13:06:28.407074       1 controllerserver.go:423] Attach operation successful: volume "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly" attached to node "3727k8s000".
I0911 13:06:28.407431       1 controllerserver.go:438] attach volume "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly" to node "3727k8s000" successfully
I0911 13:06:28.407470       1 utils.go:114] GRPC response: {"publish_context":{"LUN":"0"}}
I0911 13:06:28.499404       1 utils.go:108] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I0911 13:06:28.499499       1 utils.go:109] GRPC request: {"node_id":"3727k8s000","volume_capability":{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pre-provisioned-readOnly"}
... skipping 173 lines ...
Go Version: go1.15
Platform: windows/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0911 12:32:34.801965    5152 azure.go:50] reading cloud config from secret
W0911 12:32:35.343153    5152 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 12:32:35.343153    5152 azure.go:56] could not read cloud config from secret
I0911 12:32:35.343153    5152 azure.go:67] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0911 12:32:35.353138    5152 azure.go:77] read cloud config from file: C:\k\azure.json successfully
I0911 12:32:35.356126    5152 azure_auth.go:232] Using AzurePublicCloud environment
I0911 12:32:35.356126    5152 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
I0911 12:32:35.357138    5152 azure_interfaceclient.go:62] Azure InterfacesClient (read ops) using rate limit config: QPS=1, bucket=5
... skipping 78 lines ...
I0911 12:34:17.945262    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:34:17.945262    5152 utils.go:109] GRPC request: {}
I0911 12:34:17.946262    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:34:17.946262    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:34:17.952277    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:34:17.952277    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-1fb32da7-266b-450b-bfb1-f385d1133d70","volume_path":"c:\\var\\lib\\kubelet\\pods\\337bd19b-5d34-41a6-a63d-f63b6a144ee9\\volumes\\kubernetes.io~csi\\pvc-1fb32da7-266b-450b-bfb1-f385d1133d70\\mount"}
E0911 12:34:17.953259    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\337bd19b-5d34-41a6-a63d-f63b6a144ee9\volumes\kubernetes.io~csi\pvc-1fb32da7-266b-450b-bfb1-f385d1133d70\mount does not exist
I0911 12:34:31.171966    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:34:31.171966    5152 utils.go:109] GRPC request: {}
I0911 12:34:31.172952    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:35:01.156059    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:35:01.156059    5152 utils.go:109] GRPC request: {}
I0911 12:35:01.157057    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
... skipping 112 lines ...
I0911 12:40:24.945605    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:40:24.945605    5152 utils.go:109] GRPC request: {}
I0911 12:40:24.946618    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:40:24.946618    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:40:24.949608    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:40:24.949608    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac","volume_path":"c:\\var\\lib\\kubelet\\pods\\b3e8a431-c70d-4a6a-9564-571ebc5998f5\\volumes\\kubernetes.io~csi\\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\\mount"}
E0911 12:40:24.950607    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\b3e8a431-c70d-4a6a-9564-571ebc5998f5\volumes\kubernetes.io~csi\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\mount does not exist
I0911 12:40:31.155402    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:40:31.155402    5152 utils.go:109] GRPC request: {}
I0911 12:40:31.155402    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:41:01.153692    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:41:01.153692    5152 utils.go:109] GRPC request: {}
I0911 12:41:01.153692    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:41:19.870841    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:41:19.871745    5152 utils.go:109] GRPC request: {}
I0911 12:41:19.871745    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:41:19.871745    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:41:19.875754    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:41:19.875754    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491","volume_path":"c:\\var\\lib\\kubelet\\pods\\9b01fb08-860b-45bb-a8bc-a59961c47d4a\\volumes\\kubernetes.io~csi\\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\\mount"}
E0911 12:41:19.875754    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\9b01fb08-860b-45bb-a8bc-a59961c47d4a\volumes\kubernetes.io~csi\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\mount does not exist
I0911 12:41:31.153680    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:41:31.153680    5152 utils.go:109] GRPC request: {}
I0911 12:41:31.154680    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:41:51.348871    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:41:51.348871    5152 utils.go:109] GRPC request: {}
I0911 12:41:51.351859    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:41:51.351859    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:41:51.354836    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:41:51.354836    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac","volume_path":"c:\\var\\lib\\kubelet\\pods\\b3e8a431-c70d-4a6a-9564-571ebc5998f5\\volumes\\kubernetes.io~csi\\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\\mount"}
E0911 12:41:51.355844    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\b3e8a431-c70d-4a6a-9564-571ebc5998f5\volumes\kubernetes.io~csi\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\mount does not exist
I0911 12:42:01.153600    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:42:01.153600    5152 utils.go:109] GRPC request: {}
I0911 12:42:01.153600    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:42:31.153808    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:42:31.153808    5152 utils.go:109] GRPC request: {}
I0911 12:42:31.154785    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:42:36.097332    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:42:36.097332    5152 utils.go:109] GRPC request: {}
I0911 12:42:36.098328    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:42:36.098328    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:42:36.102344    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:42:36.102344    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491","volume_path":"c:\\var\\lib\\kubelet\\pods\\9b01fb08-860b-45bb-a8bc-a59961c47d4a\\volumes\\kubernetes.io~csi\\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\\mount"}
E0911 12:42:36.102344    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\9b01fb08-860b-45bb-a8bc-a59961c47d4a\volumes\kubernetes.io~csi\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\mount does not exist
I0911 12:42:59.342423    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0911 12:42:59.342423    5152 utils.go:109] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\9b01fb08-860b-45bb-a8bc-a59961c47d4a\\volumes\\kubernetes.io~csi\\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\\mount","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491"}
I0911 12:42:59.342423    5152 nodeserver.go:225] NodeUnpublishVolume: unmounting volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491 on c:\var\lib\kubelet\pods\9b01fb08-860b-45bb-a8bc-a59961c47d4a\volumes\kubernetes.io~csi\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\mount
I0911 12:42:59.343418    5152 nodeserver.go:230] NodeUnpublishVolume: unmount volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-cd496550-1ff0-4648-89f0-4bfa632be491 on c:\var\lib\kubelet\pods\9b01fb08-860b-45bb-a8bc-a59961c47d4a\volumes\kubernetes.io~csi\pvc-cd496550-1ff0-4648-89f0-4bfa632be491\mount successfully
I0911 12:42:59.343418    5152 utils.go:114] GRPC response: {}
I0911 12:42:59.450525    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
... skipping 11 lines ...
I0911 12:43:17.996362    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:43:17.996362    5152 utils.go:109] GRPC request: {}
I0911 12:43:17.997357    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:43:17.997357    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:43:18.000358    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:43:18.000358    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac","volume_path":"c:\\var\\lib\\kubelet\\pods\\b3e8a431-c70d-4a6a-9564-571ebc5998f5\\volumes\\kubernetes.io~csi\\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\\mount"}
E0911 12:43:18.001358    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\b3e8a431-c70d-4a6a-9564-571ebc5998f5\volumes\kubernetes.io~csi\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\mount does not exist
I0911 12:43:31.153379    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:43:31.153379    5152 utils.go:109] GRPC request: {}
I0911 12:43:31.153379    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:43:41.009616    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0911 12:43:41.009616    5152 utils.go:109] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\b3e8a431-c70d-4a6a-9564-571ebc5998f5\\volumes\\kubernetes.io~csi\\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\\mount","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac"}
I0911 12:43:41.010617    5152 nodeserver.go:225] NodeUnpublishVolume: unmounting volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac on c:\var\lib\kubelet\pods\b3e8a431-c70d-4a6a-9564-571ebc5998f5\volumes\kubernetes.io~csi\pvc-ee90b3a9-8a2d-461b-b364-c0e155599bac\mount
... skipping 65 lines ...
I0911 12:47:00.943213    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:47:00.943213    5152 utils.go:109] GRPC request: {}
I0911 12:47:00.943213    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:47:00.943213    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:47:00.949211    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:47:00.949211    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-05326442-f2f6-4f58-ab0a-16f01d907219","volume_path":"c:\\var\\lib\\kubelet\\pods\\e8d69894-7699-44e1-8cc2-079857ba1799\\volumes\\kubernetes.io~csi\\pvc-05326442-f2f6-4f58-ab0a-16f01d907219\\mount"}
E0911 12:47:00.950212    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\e8d69894-7699-44e1-8cc2-079857ba1799\volumes\kubernetes.io~csi\pvc-05326442-f2f6-4f58-ab0a-16f01d907219\mount does not exist
I0911 12:47:00.952200    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:47:00.952200    5152 utils.go:109] GRPC request: {}
I0911 12:47:00.954201    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:47:00.954201    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:47:00.973200    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:47:00.973200    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-5cb01450-53ad-4817-9f88-77bcd3887571","volume_path":"c:\\var\\lib\\kubelet\\pods\\e8d69894-7699-44e1-8cc2-079857ba1799\\volumes\\kubernetes.io~csi\\pvc-5cb01450-53ad-4817-9f88-77bcd3887571\\mount"}
E0911 12:47:00.975210    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\e8d69894-7699-44e1-8cc2-079857ba1799\volumes\kubernetes.io~csi\pvc-5cb01450-53ad-4817-9f88-77bcd3887571\mount does not exist
I0911 12:47:01.153225    5152 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:47:01.153225    5152 utils.go:109] GRPC request: {}
I0911 12:47:01.154221    5152 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:47:08.960994    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:47:08.960994    5152 utils.go:109] GRPC request: {}
I0911 12:47:08.961981    5152 nodeserver.go:237] Using default NodeGetCapabilities
... skipping 303 lines ...
I0911 13:09:06.248839    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 13:09:06.248839    5152 utils.go:109] GRPC request: {}
I0911 13:09:06.249841    5152 nodeserver.go:237] Using default NodeGetCapabilities
I0911 13:09:06.249841    5152 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 13:09:06.271836    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 13:09:06.271836    5152 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods","volume_path":"c:\\var\\lib\\kubelet\\pods\\4236e059-01f5-4b6c-aa55-030fe664ac02\\volumes\\kubernetes.io~csi\\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-s98zr\\mount"}
E0911 13:09:06.283840    5152 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\4236e059-01f5-4b6c-aa55-030fe664ac02\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-s98zr\mount does not exist
I0911 13:09:12.982038    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0911 13:09:12.982038    5152 utils.go:109] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\4236e059-01f5-4b6c-aa55-030fe664ac02\\volumes\\kubernetes.io~csi\\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-s98zr\\mount","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods"}
I0911 13:09:12.983037    5152 nodeserver.go:225] NodeUnpublishVolume: unmounting volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods on c:\var\lib\kubelet\pods\4236e059-01f5-4b6c-aa55-030fe664ac02\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-s98zr\mount
I0911 13:09:12.984034    5152 nodeserver.go:230] NodeUnpublishVolume: unmount volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods on c:\var\lib\kubelet\pods\4236e059-01f5-4b6c-aa55-030fe664ac02\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-s98zr\mount successfully
I0911 13:09:12.984034    5152 utils.go:114] GRPC response: {}
I0911 13:09:13.084039    5152 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
... skipping 109 lines ...
Go Version: go1.15
Platform: windows/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0911 12:32:43.328063    5620 azure.go:50] reading cloud config from secret
W0911 12:33:04.359901    5620 azure_config.go:52] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: Get "https://10.0.0.1:443/api/v1/namespaces/kube-system/secrets/azure-cloud-provider": dial tcp 10.0.0.1:443: connectex: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond., skip initializing from secret
I0911 12:33:04.360354    5620 azure.go:56] could not read cloud config from secret
I0911 12:33:04.360354    5620 azure.go:67] use default AZURE_CREDENTIAL_FILE env var: C:\k\azure.json
I0911 12:33:04.371359    5620 azure.go:77] read cloud config from file: C:\k\azure.json successfully
I0911 12:33:04.375381    5620 azure_auth.go:232] Using AzurePublicCloud environment
I0911 12:33:04.376384    5620 azure_auth.go:117] azure: using client_id+client_secret to retrieve access token
I0911 12:33:04.377349    5620 azure_interfaceclient.go:62] Azure InterfacesClient (read ops) using rate limit config: QPS=1, bucket=5
... skipping 209 lines ...
I0911 12:51:12.961613    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:51:12.961613    5620 utils.go:109] GRPC request: {}
I0911 12:51:12.962600    5620 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:51:12.962600    5620 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:51:12.966600    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:51:12.966600    5620 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a","volume_path":"c:\\var\\lib\\kubelet\\pods\\f345210c-01f8-40f8-ab3d-86c7e9e14a3b\\volumes\\kubernetes.io~csi\\pvc-e03d5227-a714-4c6b-a601-8ab3392b901a\\mount"}
E0911 12:51:12.966600    5620 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\f345210c-01f8-40f8-ab3d-86c7e9e14a3b\volumes\kubernetes.io~csi\pvc-e03d5227-a714-4c6b-a601-8ab3392b901a\mount does not exist
I0911 12:51:36.668180    5620 utils.go:108] GRPC call: /csi.v1.Identity/Probe
I0911 12:51:36.668180    5620 utils.go:109] GRPC request: {}
I0911 12:51:36.669115    5620 utils.go:114] GRPC response: {"ready":{"value":true}}
I0911 12:51:43.508104    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:51:43.508104    5620 utils.go:109] GRPC request: {}
I0911 12:51:43.509235    5620 nodeserver.go:237] Using default NodeGetCapabilities
... skipping 14 lines ...
I0911 12:52:22.334590    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:52:22.334590    5620 utils.go:109] GRPC request: {}
I0911 12:52:22.336591    5620 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:52:22.336591    5620 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 12:52:22.348578    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 12:52:22.348578    5620 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/pvc-e03d5227-a714-4c6b-a601-8ab3392b901a","volume_path":"c:\\var\\lib\\kubelet\\pods\\f345210c-01f8-40f8-ab3d-86c7e9e14a3b\\volumes\\kubernetes.io~csi\\pvc-e03d5227-a714-4c6b-a601-8ab3392b901a\\mount"}
E0911 12:52:22.350592    5620 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\f345210c-01f8-40f8-ab3d-86c7e9e14a3b\volumes\kubernetes.io~csi\pvc-e03d5227-a714-4c6b-a601-8ab3392b901a\mount does not exist
I0911 12:52:23.119186    5620 nodeserver.go:127] NodeStageVolume: format 8 and mounting at \var\lib\kubelet\plugins\kubernetes.io\csi\pv\pvc-0dd31a4e-aa59-4cb4-888e-318a95ff86ce\globalmount successfully.
I0911 12:52:23.119186    5620 utils.go:114] GRPC response: {}
I0911 12:52:23.134187    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 12:52:23.134187    5620 utils.go:109] GRPC request: {}
I0911 12:52:23.135211    5620 nodeserver.go:237] Using default NodeGetCapabilities
I0911 12:52:23.135211    5620 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
... skipping 248 lines ...
I0911 13:10:06.924106    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
I0911 13:10:06.924106    5620 utils.go:109] GRPC request: {}
I0911 13:10:06.926105    5620 nodeserver.go:237] Using default NodeGetCapabilities
I0911 13:10:06.926105    5620 utils.go:114] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":3}}},{"Type":{"Rpc":{"type":2}}}]}
I0911 13:10:06.932113    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetVolumeStats
I0911 13:10:06.932113    5620 utils.go:109] GRPC request: {"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods","volume_path":"c:\\var\\lib\\kubelet\\pods\\14a538e4-4bad-4742-968c-148f5e2010e1\\volumes\\kubernetes.io~csi\\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-cz8nr\\mount"}
E0911 13:10:06.933095    5620 utils.go:112] GRPC error: rpc error: code = NotFound desc = path c:\var\lib\kubelet\pods\14a538e4-4bad-4742-968c-148f5e2010e1\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-cz8nr\mount does not exist
I0911 13:10:13.329050    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I0911 13:10:13.329050    5620 utils.go:109] GRPC request: {"target_path":"c:\\var\\lib\\kubelet\\pods\\14a538e4-4bad-4742-968c-148f5e2010e1\\volumes\\kubernetes.io~csi\\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-cz8nr\\mount","volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods"}
I0911 13:10:13.330038    5620 nodeserver.go:225] NodeUnpublishVolume: unmounting volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods on c:\var\lib\kubelet\pods\14a538e4-4bad-4742-968c-148f5e2010e1\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-cz8nr\mount
I0911 13:10:13.332046    5620 nodeserver.go:230] NodeUnpublishVolume: unmount volume /subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-c7e03562-f427-11ea-9108-8e979541ec10/providers/Microsoft.Compute/disks/shared-disk-multiple-pods on c:\var\lib\kubelet\pods\14a538e4-4bad-4742-968c-148f5e2010e1\volumes\kubernetes.io~csi\azuredisk-8831-disk.csi.azure.com-preprovsioned-pv-cz8nr\mount successfully
I0911 13:10:13.332046    5620 utils.go:114] GRPC response: {}
I0911 13:10:13.428032    5620 utils.go:108] GRPC call: /csi.v1.Node/NodeGetCapabilities
... skipping 386 lines ...

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


Summarizing 1 Failure:

[Fail] Dynamic Provisioning [single-az] [It] should create a statefulset object, write and read to it, delete the pod and write and read to it again [kubernetes.io/azure-disk] [disk.csi.azure.com] [Windows] 
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:632

Ran 16 of 39 Specs in 3133.624 seconds
FAIL! -- 15 Passed | 1 Failed | 0 Pending | 23 Skipped
--- FAIL: TestE2E (3133.63s)
FAIL
FAIL	sigs.k8s.io/azuredisk-csi-driver/test/e2e	3133.713s
FAIL
make: *** [Makefile:70: e2e-test] Error 1
2020/09/11 13:14:16 process.go:155: Step 'make e2e-test' finished in 54m22.071336631s
2020/09/11 13:14:16 aksengine_helpers.go:421: downloading /root/tmp248120888/log-dump.sh from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2020/09/11 13:14:16 util.go:68: curl https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump.sh
2020/09/11 13:14:16 process.go:153: Running: chmod +x /root/tmp248120888/log-dump.sh
2020/09/11 13:14:16 process.go:155: Step 'chmod +x /root/tmp248120888/log-dump.sh' finished in 7.703821ms
2020/09/11 13:14:16 aksengine_helpers.go:421: downloading /root/tmp248120888/log-dump-daemonset.yaml from https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/hack/log-dump/log-dump-daemonset.yaml
... skipping 73 lines ...
Warning: Permanently added '3727k8s000' (ECDSA) to the list of known hosts.
Invoke logs_collector_script on Windows node 3727k8s000
Warning: Permanently added 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10.westus2.cloudapp.azure.com,40.64.108.68' (ECDSA) to the list of known hosts.

Authorized uses only. All activity may be monitored and reported.
Warning: Permanently added '3727k8s000' (ECDSA) to the list of known hosts.
Write-Progress : Win32 internal error "Access is denied" 0x5 occurred while reading the console output buffer. Contact 

Microsoft Customer Support Services.
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:1132 
char:9
+         Write-Progress -Activity $cmdletName -Status $status -Percent ...
+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 4 lines ...
process.
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:632 
char:30
+ ... sArchived = ZipArchiveHelper $sourceFilePaths $destinationPath $compr ...
+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : PermissionDenied: (C:\k\csi-proxy.err.log:String) [Write-Error], IOException

    + FullyQualifiedErrorId : CompressArchiveUnauthorizedAccessError,ZipArchiveHelper
 
New-Object : Exception calling ".ctor" with "1" argument(s): "Stream was not readable."
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:808 
char:38
... skipping 35 lines ...
Warning: Permanently added '3727k8s001' (ECDSA) to the list of known hosts.
Invoke logs_collector_script on Windows node 3727k8s001
Warning: Permanently added 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10.westus2.cloudapp.azure.com,40.64.108.68' (ECDSA) to the list of known hosts.

Authorized uses only. All activity may be monitored and reported.
Warning: Permanently added '3727k8s001' (ECDSA) to the list of known hosts.
Write-Progress : Win32 internal error "Access is denied" 0x5 occurred while reading the console output buffer. Contact 

Microsoft Customer Support Services.
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:1132 
char:9
+         Write-Progress -Activity $cmdletName -Status $status -Percent ...
+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 4 lines ...
process.
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:632 
char:30
+ ... sArchived = ZipArchiveHelper $sourceFilePaths $destinationPath $compr ...
+                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : PermissionDenied: (C:\k\csi-proxy.err.log:String) [Write-Error], IOException

    + FullyQualifiedErrorId : CompressArchiveUnauthorizedAccessError,ZipArchiveHelper
 
New-Object : Exception calling ".ctor" with "1" argument(s): "Stream was not readable."
At 
C:\windows\system32\WindowsPowerShell\v1.0\Modules\Microsoft.PowerShell.Archive\Microsoft.PowerShell.Archive.psm1:808 
char:38
... skipping 19 lines ...
Unable to collect log files from Windows Node 3727k8s001. Skipping.
Collecting logs for vm 3727k8s002
Testing connection to host 3727k8s002.
Warning: Permanently added 'kubetest-c7e03562-f427-11ea-9108-8e979541ec10.westus2.cloudapp.azure.com,40.64.108.68' (ECDSA) to the list of known hosts.

Authorized uses only. All activity may be monitored and reported.
channel 0: open failed: connect failed: Temporary failure in name resolution

stdio forwarding failed

ssh_exchange_identification: Connection closed by remote host
2020/09/11 13:16:01 process.go:155: Step 'bash -c /root/tmp248120888/win-ci-logs-collector.sh kubetest-c7e03562-f427-11ea-9108-8e979541ec10.westus2.cloudapp.azure.com /root/tmp248120888 /etc/ssh-key-secret/ssh-private' finished in 1m3.663699235s
2020/09/11 13:16:01 aksengine.go:1118: Deleting resource group: kubetest-c7e03562-f427-11ea-9108-8e979541ec10.
{"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-11T13:22:23Z"}