This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: fix: reduce VMSS throttling when throttling happens
Resultsuccess
Tests 0 failed / 27 succeeded
Started2022-09-07 13:04
Elapsed49m16s
Revision
Refs 1498
uploadercrier
uploadercrier

No Test Failures!


Show 27 Passed Tests

Show 46 Skipped Tests

Error lines from build-log.txt

... skipping 95 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0   178k      0 --:--:-- --:--:-- --:--:--  178k
Downloading https://get.helm.sh/helm-v3.9.4-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:v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azuredisk-csi:v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 not found: manifest unknown: manifest tagged by "v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-09-07T13:13:13Z -extldflags "-static""  -mod vendor -o _output/amd64/azurediskplugin.exe ./pkg/azurediskplugin
docker buildx rm container-builder || true
error: no builder "container-builder" found
docker buildx create --use --name=container-builder
container-builder
# enable qemu for arm64 build
# https://github.com/docker/buildx/issues/464#issuecomment-741507760
docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64
Unable to find image 'tonistiigi/binfmt:latest' locally
... skipping 1630 lines ...
                    type: string
                type: object
                oneOf:
                - required: ["persistentVolumeClaimName"]
                - required: ["volumeSnapshotContentName"]
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 60 lines ...
                    type: string
                  volumeSnapshotContentName:
                    description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable.
                    type: string
                type: object
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 254 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 108 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 861 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.5.0"
          args:
            - "-csi-address=$(ADDRESS)"
            - "-v=2"
            - "-leader-election"
            - "--leader-election-namespace=kube-system"
            - '-handle-volume-inuse-error=false'
            - '-feature-gates=RecoverVolumeExpansionFailure=true'
            - "-timeout=240s"
          env:
            - name: ADDRESS
              value: /csi/csi.sock
          volumeMounts:
... skipping 208 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:22:47.288: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ptfn2" in namespace "azuredisk-8081" to be "Succeeded or Failed"
Sep  7 13:22:47.396: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 107.989088ms
Sep  7 13:22:49.505: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216408044s
Sep  7 13:22:51.614: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.325280699s
Sep  7 13:22:53.722: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.43394292s
Sep  7 13:22:55.834: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545800935s
Sep  7 13:22:57.945: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.657093061s
Sep  7 13:23:00.055: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 12.766555322s
Sep  7 13:23:02.164: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 14.87586038s
Sep  7 13:23:04.273: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 16.98421937s
Sep  7 13:23:06.382: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 19.093260624s
Sep  7 13:23:08.491: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Pending", Reason="", readiness=false. Elapsed: 21.202203814s
Sep  7 13:23:10.600: INFO: Pod "azuredisk-volume-tester-ptfn2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.3112554s
STEP: Saw pod success
Sep  7 13:23:10.600: INFO: Pod "azuredisk-volume-tester-ptfn2" satisfied condition "Succeeded or Failed"
Sep  7 13:23:10.600: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-ptfn2"
Sep  7 13:23:10.732: INFO: Pod azuredisk-volume-tester-ptfn2 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-ptfn2 in namespace azuredisk-8081
STEP: validating provisioned PV
STEP: checking the PV
... skipping 97 lines ...
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod has 'FailedMount' event
Sep  7 13:24:11.328: INFO: deleting Pod "azuredisk-5466"/"azuredisk-volume-tester-hlmnz"
Sep  7 13:24:11.442: INFO: Error getting logs for pod azuredisk-volume-tester-hlmnz: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-hlmnz)
STEP: Deleting pod azuredisk-volume-tester-hlmnz in namespace azuredisk-5466
STEP: validating provisioned PV
STEP: checking the PV
Sep  7 13:24:11.769: INFO: deleting PVC "azuredisk-5466"/"pvc-zwkkb"
Sep  7 13:24:11.769: INFO: Deleting PersistentVolumeClaim "pvc-zwkkb"
STEP: waiting for claim's PV "pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace" to be deleted
... skipping 57 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:26:37.522: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fkv4q" in namespace "azuredisk-2790" to be "Succeeded or Failed"
Sep  7 13:26:37.630: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 108.088656ms
Sep  7 13:26:39.740: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.217920661s
Sep  7 13:26:41.848: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.325597556s
Sep  7 13:26:43.957: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435246721s
Sep  7 13:26:46.066: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 8.543769194s
Sep  7 13:26:48.175: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 10.653037583s
Sep  7 13:26:50.284: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 12.762239624s
Sep  7 13:26:52.394: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 14.871912921s
Sep  7 13:26:54.503: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Pending", Reason="", readiness=false. Elapsed: 16.980749855s
Sep  7 13:26:56.612: INFO: Pod "azuredisk-volume-tester-fkv4q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 19.08939394s
STEP: Saw pod success
Sep  7 13:26:56.612: INFO: Pod "azuredisk-volume-tester-fkv4q" satisfied condition "Succeeded or Failed"
Sep  7 13:26:56.612: INFO: deleting Pod "azuredisk-2790"/"azuredisk-volume-tester-fkv4q"
Sep  7 13:26:56.753: INFO: Pod azuredisk-volume-tester-fkv4q has the following logs: e2e-test

STEP: Deleting pod azuredisk-volume-tester-fkv4q in namespace azuredisk-2790
STEP: validating provisioned PV
STEP: checking the PV
... skipping 39 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Sep  7 13:27:35.479: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-m6kvq" in namespace "azuredisk-5356" to be "Error status code"
Sep  7 13:27:35.587: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 107.989707ms
Sep  7 13:27:37.696: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216746892s
Sep  7 13:27:39.805: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.325594416s
Sep  7 13:27:41.914: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435210208s
Sep  7 13:27:44.023: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.544309703s
Sep  7 13:27:46.133: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.653790115s
Sep  7 13:27:48.242: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 12.762524852s
Sep  7 13:27:50.351: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 14.871395279s
Sep  7 13:27:52.460: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 16.981247701s
Sep  7 13:27:54.569: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Pending", Reason="", readiness=false. Elapsed: 19.089816618s
Sep  7 13:27:56.678: INFO: Pod "azuredisk-volume-tester-m6kvq": Phase="Failed", Reason="", readiness=false. Elapsed: 21.198431197s
STEP: Saw pod failure
Sep  7 13:27:56.678: INFO: Pod "azuredisk-volume-tester-m6kvq" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Sep  7 13:27:56.789: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-m6kvq"
Sep  7 13:27:56.900: INFO: Pod azuredisk-volume-tester-m6kvq has the following logs: touch: /mnt/test-1/data: Read-only file system

STEP: Deleting pod azuredisk-volume-tester-m6kvq in namespace azuredisk-5356
STEP: validating provisioned PV
... skipping 381 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:35:56.788: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-jc9pd" in namespace "azuredisk-59" to be "Succeeded or Failed"
Sep  7 13:35:56.896: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 107.515ms
Sep  7 13:35:59.004: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.215911958s
Sep  7 13:36:01.114: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.325632289s
Sep  7 13:36:03.224: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435434823s
Sep  7 13:36:05.334: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545406649s
Sep  7 13:36:07.444: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.65561015s
... skipping 5 lines ...
Sep  7 13:36:20.107: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 23.318240913s
Sep  7 13:36:22.216: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 25.427971201s
Sep  7 13:36:24.325: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 27.536890853s
Sep  7 13:36:26.435: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Pending", Reason="", readiness=false. Elapsed: 29.646110073s
Sep  7 13:36:28.546: INFO: Pod "azuredisk-volume-tester-jc9pd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 31.757621295s
STEP: Saw pod success
Sep  7 13:36:28.546: INFO: Pod "azuredisk-volume-tester-jc9pd" satisfied condition "Succeeded or Failed"
Sep  7 13:36:28.546: INFO: deleting Pod "azuredisk-59"/"azuredisk-volume-tester-jc9pd"
Sep  7 13:36:28.685: INFO: Pod azuredisk-volume-tester-jc9pd has the following logs: hello world
hello world
hello world

STEP: Deleting pod azuredisk-volume-tester-jc9pd in namespace azuredisk-59
... skipping 68 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:37:19.226: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-z96wx" in namespace "azuredisk-2546" to be "Succeeded or Failed"
Sep  7 13:37:19.335: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 109.219524ms
Sep  7 13:37:21.446: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219662856s
Sep  7 13:37:23.557: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.330682315s
Sep  7 13:37:25.668: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.44214638s
Sep  7 13:37:27.783: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.557360389s
Sep  7 13:37:29.894: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.667733425s
... skipping 4 lines ...
Sep  7 13:37:40.447: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 21.220944494s
Sep  7 13:37:42.558: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 23.332254221s
Sep  7 13:37:44.669: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 25.442796s
Sep  7 13:37:46.779: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Pending", Reason="", readiness=false. Elapsed: 27.552862687s
Sep  7 13:37:48.889: INFO: Pod "azuredisk-volume-tester-z96wx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 29.662979913s
STEP: Saw pod success
Sep  7 13:37:48.889: INFO: Pod "azuredisk-volume-tester-z96wx" satisfied condition "Succeeded or Failed"
Sep  7 13:37:48.889: INFO: deleting Pod "azuredisk-2546"/"azuredisk-volume-tester-z96wx"
Sep  7 13:37:49.031: INFO: Pod azuredisk-volume-tester-z96wx has the following logs: 100+0 records in
100+0 records out
104857600 bytes (100.0MB) copied, 0.052699 seconds, 1.9GB/s
hello world

... skipping 116 lines ...
STEP: creating a PVC
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:38:37.707: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dsrv8" in namespace "azuredisk-8582" to be "Succeeded or Failed"
Sep  7 13:38:37.816: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 109.027224ms
Sep  7 13:38:39.926: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219106696s
Sep  7 13:38:42.035: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.328964711s
Sep  7 13:38:44.147: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.439982334s
Sep  7 13:38:46.257: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.550728758s
Sep  7 13:38:48.369: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.662052299s
... skipping 5 lines ...
Sep  7 13:39:01.028: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 23.32101402s
Sep  7 13:39:03.138: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 25.431068143s
Sep  7 13:39:05.247: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 27.540712107s
Sep  7 13:39:07.358: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Pending", Reason="", readiness=false. Elapsed: 29.65104044s
Sep  7 13:39:09.469: INFO: Pod "azuredisk-volume-tester-dsrv8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 31.762145387s
STEP: Saw pod success
Sep  7 13:39:09.469: INFO: Pod "azuredisk-volume-tester-dsrv8" satisfied condition "Succeeded or Failed"
Sep  7 13:39:09.469: INFO: deleting Pod "azuredisk-8582"/"azuredisk-volume-tester-dsrv8"
Sep  7 13:39:09.604: INFO: Pod azuredisk-volume-tester-dsrv8 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-dsrv8 in namespace azuredisk-8582
STEP: validating provisioned PV
STEP: checking the PV
... skipping 422 lines ...

    test case is only available for CSI drivers

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/suite_test.go:304
------------------------------
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:164
STEP: Creating a kubernetes client
Sep  7 13:43:20.109: INFO: >>> kubeConfig: /root/tmp2315661659/kubeconfig/kubeconfig.westeurope.json
STEP: Building a namespace api object, basename azuredisk
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
... skipping 3 lines ...

S [SKIPPING] [0.973 seconds]
Pre-Provisioned
/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:37
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69
    should fail when maxShares is invalid [disk.csi.azure.com][windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:164

    test case is only available for CSI drivers

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/suite_test.go:304
------------------------------
... skipping 54 lines ...
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
I0907 13:43:23.807671   14337 azuredisk_driver.go:56] Using azure disk driver: kubernetes.io/azure-disk
STEP: Successfully provisioned AzureDisk volume: "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pre-provisioned-inline-volume"

STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Sep  7 13:43:29.924: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-c84p7" in namespace "azuredisk-8470" to be "Succeeded or Failed"
Sep  7 13:43:30.031: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 107.433216ms
Sep  7 13:43:32.140: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216341432s
Sep  7 13:43:34.250: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.326301576s
Sep  7 13:43:36.359: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435253648s
Sep  7 13:43:38.469: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545053434s
Sep  7 13:43:40.579: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.655066548s
Sep  7 13:43:42.688: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 12.763567167s
Sep  7 13:43:44.797: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 14.872446301s
Sep  7 13:43:46.907: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 16.983253555s
Sep  7 13:43:49.017: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 19.092729445s
Sep  7 13:43:51.125: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Pending", Reason="", readiness=false. Elapsed: 21.200725085s
Sep  7 13:43:53.234: INFO: Pod "azuredisk-volume-tester-c84p7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 23.309461698s
STEP: Saw pod success
Sep  7 13:43:53.234: INFO: Pod "azuredisk-volume-tester-c84p7" satisfied condition "Succeeded or Failed"
Sep  7 13:43:53.234: INFO: deleting Pod "azuredisk-8470"/"azuredisk-volume-tester-c84p7"
Sep  7 13:43:53.368: INFO: Pod azuredisk-volume-tester-c84p7 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-c84p7 in namespace azuredisk-8470
Sep  7 13:43:53.482: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "azuredisk-8470" for this suite.
... skipping 218 lines ...
I0907 13:09:56.030557       1 azure_securitygroupclient.go:64] Azure SecurityGroupsClient (read ops) using rate limit config: QPS=6, bucket=20
I0907 13:09:56.030560       1 azure_securitygroupclient.go:67] Azure SecurityGroupsClient (write ops) using rate limit config: QPS=100, bucket=1000
I0907 13:09:56.030584       1 azure_publicipclient.go:64] Azure PublicIPAddressesClient (read ops) using rate limit config: QPS=6, bucket=20
I0907 13:09:56.030588       1 azure_publicipclient.go:67] Azure PublicIPAddressesClient (write ops) using rate limit config: QPS=100, bucket=1000
I0907 13:09:56.037363       1 azure.go:743] Setting up informers for Azure cloud provider
I0907 13:09:56.044593       1 shared_informer.go:240] Waiting for caches to sync for tokens
W0907 13:09:56.104493       1 azure_config.go:53] Failed to get cloud-config from secret: failed to get secret azure-cloud-provider: secrets "azure-cloud-provider" is forbidden: User "system:serviceaccount:kube-system:azure-cloud-provider" cannot get resource "secrets" in API group "" in the namespace "kube-system", skip initializing from secret
I0907 13:09:56.104528       1 controllermanager.go:576] Starting "horizontalpodautoscaling"
I0907 13:09:56.128568       1 controllermanager.go:605] Started "horizontalpodautoscaling"
I0907 13:09:56.128859       1 controllermanager.go:576] Starting "pvc-protection"
I0907 13:09:56.129158       1 horizontal.go:168] Starting HPA controller
I0907 13:09:56.130187       1 shared_informer.go:240] Waiting for caches to sync for HPA
I0907 13:09:56.135238       1 controllermanager.go:605] Started "pvc-protection"
... skipping 43 lines ...
I0907 13:09:56.286769       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/storageos"
I0907 13:09:56.286842       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/fc"
I0907 13:09:56.286917       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/iscsi"
I0907 13:09:56.287001       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/csi"
I0907 13:09:56.287215       1 controllermanager.go:605] Started "attachdetach"
I0907 13:09:56.287297       1 controllermanager.go:576] Starting "persistentvolume-expander"
W0907 13:09:56.290559       1 actual_state_of_world.go:539] Failed to update statusUpdateNeeded field in actual state of world: Failed to set statusUpdateNeeded to needed true, because nodeName="k8s-master-39118761-0" does not exist
I0907 13:09:56.290589       1 attach_detach_controller.go:328] Starting attach detach controller
I0907 13:09:56.290597       1 shared_informer.go:240] Waiting for caches to sync for attach detach
I0907 13:09:56.303292       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/cinder"
I0907 13:09:56.303317       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/azure-disk"
I0907 13:09:56.303325       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/vsphere-volume"
I0907 13:09:56.303371       1 plugins.go:643] "Loaded volume plugin" pluginName="kubernetes.io/portworx-volume"
... skipping 53 lines ...
I0907 13:09:57.900015       1 controllermanager.go:576] Starting "cloud-node-lifecycle"
I0907 13:09:57.900047       1 controller.go:170] Starting ephemeral volume controller
I0907 13:09:57.900053       1 shared_informer.go:240] Waiting for caches to sync for ephemeral
I0907 13:09:58.047599       1 node_lifecycle_controller.go:77] Sending events to api server
I0907 13:09:58.048368       1 controllermanager.go:605] Started "cloud-node-lifecycle"
I0907 13:09:58.054742       1 controllermanager.go:576] Starting "pv-protection"
W0907 13:09:58.142929       1 actual_state_of_world.go:539] Failed to update statusUpdateNeeded field in actual state of world: Failed to set statusUpdateNeeded to needed true, because nodeName="k8s-agentpool1-39118761-0" does not exist
I0907 13:09:58.153848       1 ttl_controller.go:276] "Changed ttl annotation" node="k8s-agentpool1-39118761-0" new_ttl="0s"
I0907 13:09:58.196969       1 controllermanager.go:605] Started "pv-protection"
I0907 13:09:58.196993       1 controllermanager.go:576] Starting "nodelifecycle"
I0907 13:09:58.197047       1 pv_protection_controller.go:79] Starting PV protection controller
I0907 13:09:58.197054       1 shared_informer.go:240] Waiting for caches to sync for PV protection
W0907 13:09:58.215716       1 actual_state_of_world.go:539] Failed to update statusUpdateNeeded field in actual state of world: Failed to set statusUpdateNeeded to needed true, because nodeName="k8s-agentpool1-39118761-1" does not exist
I0907 13:09:58.222786       1 ttl_controller.go:276] "Changed ttl annotation" node="k8s-agentpool1-39118761-1" new_ttl="0s"
I0907 13:09:58.246935       1 node_lifecycle_controller.go:377] Sending events to api server.
I0907 13:09:58.247325       1 taint_manager.go:163] "Sending events to api server"
I0907 13:09:58.247457       1 node_lifecycle_controller.go:505] Controller will reconcile labels.
I0907 13:09:58.247506       1 controllermanager.go:605] Started "nodelifecycle"
I0907 13:09:58.247530       1 controllermanager.go:576] Starting "replicaset"
... skipping 205 lines ...
I0907 13:10:28.560294       1 azure_routes.go:444] CreateRoute: route created. clusterName="kubetest-ttcndx8r" instance="k8s-agentpool1-39118761-0" cidr="10.244.2.0/24"
I0907 13:10:28.560539       1 route_controller.go:214] Created route for node k8s-agentpool1-39118761-0 10.244.2.0/24 with hint 8a8e972d-8e56-4f6f-a01c-d7fb8d174a78 after 9.509882741s
I0907 13:10:28.560307       1 azure_routes.go:444] CreateRoute: route created. clusterName="kubetest-ttcndx8r" instance="k8s-agentpool1-39118761-1" cidr="10.244.0.0/24"
I0907 13:10:28.560565       1 route_controller.go:214] Created route for node k8s-agentpool1-39118761-1 10.244.0.0/24 with hint d3dec249-cce4-4a39-8195-5d4803927b5f after 9.510229746s
I0907 13:10:28.560323       1 azure_routes.go:444] CreateRoute: route created. clusterName="kubetest-ttcndx8r" instance="k8s-master-39118761-0" cidr="10.244.1.0/24"
I0907 13:10:28.560575       1 route_controller.go:214] Created route for node k8s-master-39118761-0 10.244.1.0/24 with hint be544ec9-5635-47c3-86c3-a4705c52a78a after 9.510211746s
I0907 13:10:28.560733       1 route_controller.go:308] Patching node status k8s-master-39118761-0 with true previous condition was:&NodeCondition{Type:NetworkUnavailable,Status:True,LastHeartbeatTime:2022-09-07 13:09:59 +0000 UTC,LastTransitionTime:2022-09-07 13:09:59 +0000 UTC,Reason:NoRouteCreated,Message:RouteController failed to create a route,}
I0907 13:10:28.560601       1 route_controller.go:308] Patching node status k8s-agentpool1-39118761-1 with true previous condition was:&NodeCondition{Type:NetworkUnavailable,Status:True,LastHeartbeatTime:2022-09-07 13:09:59 +0000 UTC,LastTransitionTime:2022-09-07 13:09:59 +0000 UTC,Reason:NoRouteCreated,Message:RouteController failed to create a route,}
I0907 13:10:28.560904       1 route_controller.go:308] Patching node status k8s-agentpool1-39118761-0 with true previous condition was:&NodeCondition{Type:NetworkUnavailable,Status:True,LastHeartbeatTime:2022-09-07 13:09:59 +0000 UTC,LastTransitionTime:2022-09-07 13:09:59 +0000 UTC,Reason:NoRouteCreated,Message:RouteController failed to create a route,}
I0907 13:10:29.084085       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:29.084113       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:29.084120       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:39.052094       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:39.052344       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:39.052446       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:49.052894       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:49.052896       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:49.052914       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:57.587733       1 replica_set.go:563] "Too few replicas" replicaSet="kube-system/coredns-7cf78b68d8" need=1 creating=1
I0907 13:10:57.588367       1 event.go:294] "Event occurred" object="kube-system/coredns" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set coredns-7cf78b68d8 to 1"
I0907 13:10:57.664044       1 deployment_controller.go:490] "Error syncing deployment" deployment="kube-system/coredns" err="Operation cannot be fulfilled on deployments.apps \"coredns\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:10:57.665939       1 event.go:294] "Event occurred" object="kube-system/coredns-autoscaler" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set coredns-autoscaler-cc76d9bff to 1"
I0907 13:10:57.666365       1 replica_set.go:563] "Too few replicas" replicaSet="kube-system/coredns-autoscaler-cc76d9bff" need=1 creating=1
I0907 13:10:57.712199       1 event.go:294] "Event occurred" object="kube-system/coredns-7cf78b68d8" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: coredns-7cf78b68d8-46qtw"
I0907 13:10:57.712415       1 event.go:294] "Event occurred" object="kube-system/coredns-autoscaler-cc76d9bff" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: coredns-autoscaler-cc76d9bff-htk5q"
I0907 13:10:57.788114       1 deployment_controller.go:490] "Error syncing deployment" deployment="kube-system/coredns-autoscaler" err="Operation cannot be fulfilled on deployments.apps \"coredns-autoscaler\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:10:58.824360       1 event.go:294] "Event occurred" object="kube-system/azure-ip-masq-agent" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: azure-ip-masq-agent-khkzc"
I0907 13:10:58.900249       1 event.go:294] "Event occurred" object="kube-system/azure-ip-masq-agent" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: azure-ip-masq-agent-dprxc"
I0907 13:10:58.904259       1 event.go:294] "Event occurred" object="kube-system/kube-proxy" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: kube-proxy-ggzbj"
I0907 13:10:58.910299       1 event.go:294] "Event occurred" object="kube-system/azure-ip-masq-agent" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: azure-ip-masq-agent-4kcfc"
I0907 13:10:58.972350       1 event.go:294] "Event occurred" object="kube-system/kube-proxy" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: kube-proxy-b4kwh"
I0907 13:10:58.983453       1 event.go:294] "Event occurred" object="kube-system/kube-proxy" kind="DaemonSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: kube-proxy-dt796"
I0907 13:10:59.055823       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:59.055849       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:10:59.055856       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:01.449241       1 replica_set.go:563] "Too few replicas" replicaSet="kube-system/metrics-server-5b8986d847" need=1 creating=1
I0907 13:11:01.452475       1 event.go:294] "Event occurred" object="kube-system/metrics-server" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set metrics-server-5b8986d847 to 1"
I0907 13:11:01.492920       1 event.go:294] "Event occurred" object="kube-system/metrics-server-5b8986d847" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: metrics-server-5b8986d847-m29h9"
I0907 13:11:01.509452       1 deployment_controller.go:490] "Error syncing deployment" deployment="kube-system/metrics-server" err="Operation cannot be fulfilled on deployments.apps \"metrics-server\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:11:09.056537       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:09.056572       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:09.056579       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:11:10.734659       1 resource_quota_controller.go:413] unable to retrieve the complete list of server APIs: metrics.k8s.io/v1beta1: the server is currently unable to handle the request
W0907 13:11:11.132792       1 garbagecollector.go:707] failed to discover some groups: map[metrics.k8s.io/v1beta1:the server is currently unable to handle the request]
I0907 13:11:19.056751       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:19.056772       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:19.056782       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:29.057494       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:29.057528       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:11:29.057536       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 195 lines ...
I0907 13:22:15.042017       1 replica_set.go:563] "Too few replicas" replicaSet="kube-system/csi-snapshot-controller-77575f995f" need=2 creating=2
I0907 13:22:15.047142       1 event.go:294] "Event occurred" object="kube-system/csi-snapshot-controller" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set csi-snapshot-controller-77575f995f to 2"
I0907 13:22:15.087516       1 event.go:294] "Event occurred" object="kube-system/csi-snapshot-controller-77575f995f" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: csi-snapshot-controller-77575f995f-kp9pg"
I0907 13:22:15.098931       1 event.go:294] "Event occurred" object="kube-system/csi-azuredisk-controller" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set csi-azuredisk-controller-77764bbd44 to 2"
I0907 13:22:15.103269       1 replica_set.go:563] "Too few replicas" replicaSet="kube-system/csi-azuredisk-controller-77764bbd44" need=2 creating=2
I0907 13:22:15.138853       1 event.go:294] "Event occurred" object="kube-system/csi-azuredisk-controller-77764bbd44" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: csi-azuredisk-controller-77764bbd44-btnjq"
I0907 13:22:15.153193       1 deployment_controller.go:490] "Error syncing deployment" deployment="kube-system/csi-snapshot-controller" err="Operation cannot be fulfilled on deployments.apps \"csi-snapshot-controller\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:22:15.153269       1 event.go:294] "Event occurred" object="kube-system/csi-snapshot-controller-77575f995f" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: csi-snapshot-controller-77575f995f-fdb7q"
I0907 13:22:15.161060       1 deployment_controller.go:490] "Error syncing deployment" deployment="kube-system/csi-azuredisk-controller" err="Operation cannot be fulfilled on deployments.apps \"csi-azuredisk-controller\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:22:15.188263       1 event.go:294] "Event occurred" object="kube-system/csi-azuredisk-controller-77764bbd44" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: csi-azuredisk-controller-77764bbd44-bpd6g"
I0907 13:22:19.096602       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:22:19.096642       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:22:19.096650       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:22:29.096755       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:22:29.096764       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 40 lines ...
I0907 13:23:29.190851       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:29.190867       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:29.431730       1 operation_generator.go:528] DetachVolume.Detach succeeded for volume "pvc-e30b0fd1-c509-4a47-baed-7a9124befd0b" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-e30b0fd1-c509-4a47-baed-7a9124befd0b") on node "k8s-agentpool1-39118761-0" 
I0907 13:23:39.100211       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:39.100235       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:39.100218       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:23:43.519435       1 pv_protection_controller.go:114] PV pvc-e30b0fd1-c509-4a47-baed-7a9124befd0b failed with : Operation cannot be fulfilled on persistentvolumes "pvc-e30b0fd1-c509-4a47-baed-7a9124befd0b": the object has been modified; please apply your changes to the latest version and try again
I0907 13:23:43.523368       1 pv_controller_base.go:533] deletion of claim "azuredisk-8081/pvc-xz4zf" was already processed
I0907 13:23:49.100567       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:49.100568       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:49.100587       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:23:52.650103       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-8081/default: secrets "default-token-4bt7w" is forbidden: unable to create new content in namespace azuredisk-8081 because it is being terminated
I0907 13:23:52.950494       1 event.go:294] "Event occurred" object="azuredisk-5466/pvc-zwkkb" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:23:53.068057       1 event.go:294] "Event occurred" object="azuredisk-5466/pvc-zwkkb" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:23:55.420305       1 pv_controller.go:887] volume "pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace" entered phase "Bound"
I0907 13:23:55.420606       1 pv_controller.go:990] volume "pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace" bound to claim "azuredisk-5466/pvc-zwkkb"
I0907 13:23:55.427073       1 pv_controller.go:831] claim "azuredisk-5466/pvc-zwkkb" entered phase "Bound"
I0907 13:23:56.108713       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace") from node "k8s-agentpool1-39118761-0" 
E0907 13:23:56.311486       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-4728/default: serviceaccounts "default" not found
I0907 13:23:57.761156       1 namespace_controller.go:185] Namespace has been deleted azuredisk-8081
I0907 13:23:59.100895       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:59.100896       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:59.100909       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:23:59.546739       1 namespace_controller.go:185] Namespace has been deleted azuredisk-2540
I0907 13:24:01.384052       1 namespace_controller.go:185] Namespace has been deleted azuredisk-4728
... skipping 62 lines ...
I0907 13:26:39.110996       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:26:39.111012       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:26:39.877596       1 pv_controller.go:887] volume "pvc-938911ae-b305-40aa-b9d5-12d160908aee" entered phase "Bound"
I0907 13:26:39.877633       1 pv_controller.go:990] volume "pvc-938911ae-b305-40aa-b9d5-12d160908aee" bound to claim "azuredisk-2790/pvc-kkkgs"
I0907 13:26:39.885034       1 pv_controller.go:831] claim "azuredisk-2790/pvc-kkkgs" entered phase "Bound"
I0907 13:26:40.563301       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-938911ae-b305-40aa-b9d5-12d160908aee" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-938911ae-b305-40aa-b9d5-12d160908aee") from node "k8s-agentpool1-39118761-1" 
E0907 13:26:40.701792       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-5466/default: secrets "default-token-vr4b7" is forbidden: unable to create new content in namespace azuredisk-5466 because it is being terminated
I0907 13:26:45.795548       1 namespace_controller.go:185] Namespace has been deleted azuredisk-5466
I0907 13:26:46.389414       1 operation_generator.go:413] AttachVolume.Attach succeeded for volume "pvc-938911ae-b305-40aa-b9d5-12d160908aee" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-938911ae-b305-40aa-b9d5-12d160908aee") from node "k8s-agentpool1-39118761-1" 
I0907 13:26:46.389563       1 event.go:294] "Event occurred" object="azuredisk-2790/azuredisk-volume-tester-fkv4q" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"pvc-938911ae-b305-40aa-b9d5-12d160908aee\" "
I0907 13:26:49.111341       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:26:49.111346       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:26:49.111360       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 9 lines ...
I0907 13:27:09.112495       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:09.112509       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:14.677218       1 operation_generator.go:528] DetachVolume.Detach succeeded for volume "pvc-938911ae-b305-40aa-b9d5-12d160908aee" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-938911ae-b305-40aa-b9d5-12d160908aee") on node "k8s-agentpool1-39118761-1" 
I0907 13:27:19.113121       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:19.113136       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:19.113161       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:27:28.719572       1 pv_protection_controller.go:114] PV pvc-938911ae-b305-40aa-b9d5-12d160908aee failed with : Operation cannot be fulfilled on persistentvolumes "pvc-938911ae-b305-40aa-b9d5-12d160908aee": the object has been modified; please apply your changes to the latest version and try again
I0907 13:27:28.724717       1 pv_controller_base.go:533] deletion of claim "azuredisk-2790/pvc-kkkgs" was already processed
I0907 13:27:29.113674       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:29.113684       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:29.113700       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:35.327335       1 event.go:294] "Event occurred" object="azuredisk-5356/pvc-jk4ln" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:27:35.437081       1 event.go:294] "Event occurred" object="azuredisk-5356/pvc-jk4ln" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:27:35.437312       1 event.go:294] "Event occurred" object="azuredisk-5356/pvc-jk4ln" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:27:37.962277       1 pv_controller.go:887] volume "pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80" entered phase "Bound"
I0907 13:27:37.962308       1 pv_controller.go:990] volume "pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80" bound to claim "azuredisk-5356/pvc-jk4ln"
I0907 13:27:37.969816       1 pv_controller.go:831] claim "azuredisk-5356/pvc-jk4ln" entered phase "Bound"
I0907 13:27:38.537669       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80") from node "k8s-agentpool1-39118761-1" 
E0907 13:27:38.649516       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-2790/default: secrets "default-token-d7m67" is forbidden: unable to create new content in namespace azuredisk-2790 because it is being terminated
I0907 13:27:39.114295       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:39.114308       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:39.114324       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:43.785426       1 namespace_controller.go:185] Namespace has been deleted azuredisk-2790
I0907 13:27:49.165991       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:27:49.165992       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 12 lines ...
I0907 13:28:09.116315       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:09.116333       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:15.712756       1 operation_generator.go:528] DetachVolume.Detach succeeded for volume "pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80") on node "k8s-agentpool1-39118761-1" 
I0907 13:28:19.116592       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:19.116613       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:19.116598       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:28:28.942594       1 pv_protection_controller.go:114] PV pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80 failed with : Operation cannot be fulfilled on persistentvolumes "pvc-4aed7ef9-c5d1-4b25-b335-cc06a07c6a80": the object has been modified; please apply your changes to the latest version and try again
I0907 13:28:28.954612       1 pv_controller_base.go:533] deletion of claim "azuredisk-5356/pvc-jk4ln" was already processed
I0907 13:28:29.116749       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:29.116760       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:29.116774       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:28:35.491991       1 event.go:294] "Event occurred" object="azuredisk-5194/pvc-hlhmm" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:28:35.607774       1 event.go:294] "Event occurred" object="azuredisk-5194/pvc-hlhmm" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
... skipping 141 lines ...
I0907 13:32:49.131363       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:32:49.131379       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:32:54.991219       1 event.go:294] "Event occurred" object="azuredisk-1353/pvc-lhxz9" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:32:55.104601       1 replica_set.go:563] "Too few replicas" replicaSet="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7" need=1 creating=1
I0907 13:32:55.105022       1 event.go:294] "Event occurred" object="azuredisk-1353/azuredisk-volume-tester-pxhjn" kind="Deployment" apiVersion="apps/v1" type="Normal" reason="ScalingReplicaSet" message="Scaled up replica set azuredisk-volume-tester-pxhjn-7cfd85f9d7 to 1"
I0907 13:32:55.113772       1 event.go:294] "Event occurred" object="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: azuredisk-volume-tester-pxhjn-7cfd85f9d7-lmq59"
I0907 13:32:55.118146       1 deployment_controller.go:490] "Error syncing deployment" deployment="azuredisk-1353/azuredisk-volume-tester-pxhjn" err="Operation cannot be fulfilled on deployments.apps \"azuredisk-volume-tester-pxhjn\": the object has been modified; please apply your changes to the latest version and try again"
I0907 13:32:55.125695       1 event.go:294] "Event occurred" object="azuredisk-1353/pvc-lhxz9" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:32:55.126454       1 event.go:294] "Event occurred" object="azuredisk-1353/pvc-lhxz9" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:32:55.650936       1 event.go:294] "Event occurred" object="azuredisk-1353/pvc-lhxz9" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:32:57.590328       1 pv_controller.go:887] volume "pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1" entered phase "Bound"
I0907 13:32:57.590368       1 pv_controller.go:990] volume "pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1" bound to claim "azuredisk-1353/pvc-lhxz9"
I0907 13:32:57.597084       1 pv_controller.go:831] claim "azuredisk-1353/pvc-lhxz9" entered phase "Bound"
... skipping 9 lines ...
I0907 13:33:14.132459       1 event.go:294] "Event occurred" object="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7-lmq59" kind="Pod" apiVersion="v1" type="Normal" reason="SuccessfulAttachVolume" message="AttachVolume.Attach succeeded for volume \"pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1\" "
I0907 13:33:19.133666       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:19.133707       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:19.133691       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:21.209287       1 replica_set.go:563] "Too few replicas" replicaSet="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7" need=1 creating=1
I0907 13:33:21.215046       1 event.go:294] "Event occurred" object="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7" kind="ReplicaSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="Created pod: azuredisk-volume-tester-pxhjn-7cfd85f9d7-ll5tw"
W0907 13:33:21.250828       1 reconciler.go:385] Multi-Attach error for volume "pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1") from node "k8s-agentpool1-39118761-0" Volume is already used by pods azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7-lmq59 on node k8s-agentpool1-39118761-1
I0907 13:33:21.251452       1 event.go:294] "Event occurred" object="azuredisk-1353/azuredisk-volume-tester-pxhjn-7cfd85f9d7-ll5tw" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="Multi-Attach error for volume \"pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1\" Volume is already used by pod(s) azuredisk-volume-tester-pxhjn-7cfd85f9d7-lmq59"
I0907 13:33:29.134269       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:29.134294       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:29.134303       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:39.135258       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:39.135262       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:33:39.135275       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 50 lines ...
I0907 13:35:19.140893       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:19.140907       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:22.629359       1 operation_generator.go:528] DetachVolume.Detach succeeded for volume "pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1") on node "k8s-agentpool1-39118761-0" 
I0907 13:35:29.141164       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:29.141165       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:29.141180       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:35:32.818681       1 pv_protection_controller.go:114] PV pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1 failed with : Operation cannot be fulfilled on persistentvolumes "pvc-5cc07557-d5ad-4ac3-bf2a-da6fa73f4ff1": the object has been modified; please apply your changes to the latest version and try again
I0907 13:35:32.821599       1 pv_controller_base.go:533] deletion of claim "azuredisk-1353/pvc-lhxz9" was already processed
I0907 13:35:38.610098       1 event.go:294] "Event occurred" object="azuredisk-4538/pvc-z7dzc" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:35:39.141256       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:39.141262       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:39.141357       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:40.657723       1 event.go:294] "Event occurred" object="azuredisk-4538/pvc-z7dzc" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
... skipping 5 lines ...
I0907 13:35:43.271808       1 pv_controller.go:887] volume "pvc-4de0fb8c-2215-4446-9fa0-477e506c59ac" entered phase "Released"
I0907 13:35:43.875805       1 pv_controller_base.go:533] deletion of claim "azuredisk-4538/pvc-z7dzc" was already processed
I0907 13:35:47.038286       1 namespace_controller.go:185] Namespace has been deleted azuredisk-1353
I0907 13:35:49.141707       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:49.141729       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:49.141745       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:35:54.025562       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-4538/default: secrets "default-token-t6kn9" is forbidden: unable to create new content in namespace azuredisk-4538 because it is being terminated
E0907 13:35:55.850319       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-8266/default: secrets "default-token-bf5cb" is forbidden: unable to create new content in namespace azuredisk-8266 because it is being terminated
I0907 13:35:56.190420       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-rlrqg" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:35:56.407682       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-6rdw6" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:35:56.628550       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-wdflz" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:35:56.752830       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-rlrqg" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:35:56.753536       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-rlrqg" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:35:56.761328       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-6rdw6" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:35:56.766271       1 event.go:294] "Event occurred" object="azuredisk-59/pvc-wdflz" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
E0907 13:35:57.746752       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-4376/default: secrets "default-token-8gvxh" is forbidden: unable to create new content in namespace azuredisk-4376 because it is being terminated
I0907 13:35:59.083404       1 namespace_controller.go:185] Namespace has been deleted azuredisk-4538
I0907 13:35:59.116007       1 pv_controller.go:887] volume "pvc-6f1a5d8c-8b20-410f-b462-8b1d50143a4d" entered phase "Bound"
I0907 13:35:59.116044       1 pv_controller.go:990] volume "pvc-6f1a5d8c-8b20-410f-b462-8b1d50143a4d" bound to claim "azuredisk-59/pvc-wdflz"
I0907 13:35:59.123221       1 pv_controller.go:831] claim "azuredisk-59/pvc-wdflz" entered phase "Bound"
I0907 13:35:59.141872       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:59.141883       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:59.141897       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:35:59.156458       1 pv_controller.go:887] volume "pvc-17869abf-8d23-40c7-810f-67d32629187d" entered phase "Bound"
I0907 13:35:59.156489       1 pv_controller.go:990] volume "pvc-17869abf-8d23-40c7-810f-67d32629187d" bound to claim "azuredisk-59/pvc-rlrqg"
I0907 13:35:59.165221       1 pv_controller.go:831] claim "azuredisk-59/pvc-rlrqg" entered phase "Bound"
I0907 13:35:59.220825       1 pv_controller.go:887] volume "pvc-1e2735fe-b3c9-4c95-a3c4-e44bdf096e29" entered phase "Bound"
I0907 13:35:59.221088       1 pv_controller.go:990] volume "pvc-1e2735fe-b3c9-4c95-a3c4-e44bdf096e29" bound to claim "azuredisk-59/pvc-6rdw6"
I0907 13:35:59.230579       1 pv_controller.go:831] claim "azuredisk-59/pvc-6rdw6" entered phase "Bound"
E0907 13:35:59.571980       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-7996/default: secrets "default-token-49kk8" is forbidden: unable to create new content in namespace azuredisk-7996 because it is being terminated
I0907 13:35:59.765906       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-17869abf-8d23-40c7-810f-67d32629187d" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-17869abf-8d23-40c7-810f-67d32629187d") from node "k8s-agentpool1-39118761-0" 
I0907 13:35:59.765939       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-1e2735fe-b3c9-4c95-a3c4-e44bdf096e29" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-1e2735fe-b3c9-4c95-a3c4-e44bdf096e29") from node "k8s-agentpool1-39118761-0" 
I0907 13:35:59.765954       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-6f1a5d8c-8b20-410f-b462-8b1d50143a4d" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-6f1a5d8c-8b20-410f-b462-8b1d50143a4d") from node "k8s-agentpool1-39118761-0" 
I0907 13:36:00.921761       1 namespace_controller.go:185] Namespace has been deleted azuredisk-8266
I0907 13:36:02.860033       1 namespace_controller.go:185] Namespace has been deleted azuredisk-4376
I0907 13:36:04.606426       1 namespace_controller.go:185] Namespace has been deleted azuredisk-7996
... skipping 41 lines ...
I0907 13:37:09.144896       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:37:09.144901       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:37:09.144915       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:37:11.302022       1 pvc_protection_controller.go:269] "PVC is unused" PVC="azuredisk-59/pvc-rlrqg"
I0907 13:37:11.311989       1 pv_controller.go:648] volume "pvc-17869abf-8d23-40c7-810f-67d32629187d" is released and reclaim policy "Delete" will be executed
I0907 13:37:11.316547       1 pv_controller.go:887] volume "pvc-17869abf-8d23-40c7-810f-67d32629187d" entered phase "Released"
E0907 13:37:11.866659       1 pv_protection_controller.go:114] PV pvc-17869abf-8d23-40c7-810f-67d32629187d failed with : Operation cannot be fulfilled on persistentvolumes "pvc-17869abf-8d23-40c7-810f-67d32629187d": the object has been modified; please apply your changes to the latest version and try again
I0907 13:37:11.872039       1 pv_controller_base.go:533] deletion of claim "azuredisk-59/pvc-rlrqg" was already processed
I0907 13:37:18.841907       1 event.go:294] "Event occurred" object="azuredisk-2546/pvc-4kxg2" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:37:19.066163       1 event.go:294] "Event occurred" object="azuredisk-2546/pvc-nllhx" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:37:19.145222       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:37:19.145254       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:37:19.145325       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 64 lines ...
I0907 13:38:40.110518       1 pv_controller.go:887] volume "pvc-4b608917-83b9-48ab-be47-7716efecb0b8" entered phase "Bound"
I0907 13:38:40.110553       1 pv_controller.go:990] volume "pvc-4b608917-83b9-48ab-be47-7716efecb0b8" bound to claim "azuredisk-8582/pvc-s7qtz"
I0907 13:38:40.121943       1 pv_controller.go:831] claim "azuredisk-8582/pvc-s7qtz" entered phase "Bound"
I0907 13:38:40.125724       1 pv_controller.go:887] volume "pvc-2adee4a9-5aec-4080-a5e4-88ce94326c0a" entered phase "Bound"
I0907 13:38:40.125756       1 pv_controller.go:990] volume "pvc-2adee4a9-5aec-4080-a5e4-88ce94326c0a" bound to claim "azuredisk-8582/pvc-q8xl8"
I0907 13:38:40.131986       1 pv_controller.go:831] claim "azuredisk-8582/pvc-q8xl8" entered phase "Bound"
E0907 13:38:40.477269       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-3410/default: secrets "default-token-x7hjj" is forbidden: unable to create new content in namespace azuredisk-3410 because it is being terminated
I0907 13:38:40.766042       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-4b608917-83b9-48ab-be47-7716efecb0b8" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b608917-83b9-48ab-be47-7716efecb0b8") from node "k8s-agentpool1-39118761-0" 
I0907 13:38:40.766076       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-2adee4a9-5aec-4080-a5e4-88ce94326c0a" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-2adee4a9-5aec-4080-a5e4-88ce94326c0a") from node "k8s-agentpool1-39118761-0" 
I0907 13:38:40.766091       1 reconciler.go:304] attacherDetacher.AttachVolume started for volume "pvc-b3298e2e-5942-4bcf-9ab9-e27e564061b1" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-b3298e2e-5942-4bcf-9ab9-e27e564061b1") from node "k8s-agentpool1-39118761-0" 
I0907 13:38:41.837707       1 namespace_controller.go:185] Namespace has been deleted azuredisk-2546
I0907 13:38:43.659786       1 namespace_controller.go:185] Namespace has been deleted azuredisk-1598
I0907 13:38:45.519265       1 namespace_controller.go:185] Namespace has been deleted azuredisk-3410
... skipping 45 lines ...
I0907 13:39:52.211344       1 pv_controller.go:648] volume "pvc-b3298e2e-5942-4bcf-9ab9-e27e564061b1" is released and reclaim policy "Delete" will be executed
I0907 13:39:52.214574       1 pv_controller.go:887] volume "pvc-b3298e2e-5942-4bcf-9ab9-e27e564061b1" entered phase "Released"
I0907 13:39:53.311665       1 pv_controller_base.go:533] deletion of claim "azuredisk-8582/pvc-wchqp" was already processed
I0907 13:39:59.155950       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:39:59.155966       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:39:59.155979       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:40:06.696540       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-3086/default: secrets "default-token-hmnlx" is forbidden: unable to create new content in namespace azuredisk-3086 because it is being terminated
I0907 13:40:07.057013       1 event.go:294] "Event occurred" object="azuredisk-7051/pvc-vrmd4" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:40:07.175064       1 event.go:294] "Event occurred" object="azuredisk-7051/pvc-vrmd4" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:40:07.175408       1 event.go:294] "Event occurred" object="azuredisk-7051/pvc-vrmd4" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:40:08.147281       1 namespace_controller.go:185] Namespace has been deleted azuredisk-8582
I0907 13:40:09.156805       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:40:09.156828       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 35 lines ...
I0907 13:41:29.163064       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:41:29.163070       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:41:29.163083       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:41:29.697007       1 pvc_protection_controller.go:269] "PVC is unused" PVC="azuredisk-7051/pvc-vrmd4"
I0907 13:41:29.705339       1 pv_controller.go:648] volume "pvc-937151c3-f06a-4d46-8549-0565679e6fd0" is released and reclaim policy "Delete" will be executed
I0907 13:41:29.708919       1 pv_controller.go:887] volume "pvc-937151c3-f06a-4d46-8549-0565679e6fd0" entered phase "Released"
E0907 13:41:30.442778       1 pv_protection_controller.go:114] PV pvc-937151c3-f06a-4d46-8549-0565679e6fd0 failed with : Operation cannot be fulfilled on persistentvolumes "pvc-937151c3-f06a-4d46-8549-0565679e6fd0": the object has been modified; please apply your changes to the latest version and try again
I0907 13:41:30.446835       1 pv_controller_base.go:533] deletion of claim "azuredisk-7051/pvc-vrmd4" was already processed
I0907 13:41:37.099962       1 event.go:294] "Event occurred" object="azuredisk-9183/azuredisk-volume-tester-89tzd" kind="StatefulSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="create Claim pvc-azuredisk-volume-tester-89tzd-0 Pod azuredisk-volume-tester-89tzd-0 in StatefulSet azuredisk-volume-tester-89tzd success"
I0907 13:41:37.100019       1 event.go:294] "Event occurred" object="azuredisk-9183/pvc-azuredisk-volume-tester-89tzd-0" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="WaitForFirstConsumer" message="waiting for first consumer to be created before binding"
I0907 13:41:37.107277       1 event.go:294] "Event occurred" object="azuredisk-9183/azuredisk-volume-tester-89tzd" kind="StatefulSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="create Pod azuredisk-volume-tester-89tzd-0 in StatefulSet azuredisk-volume-tester-89tzd successful"
I0907 13:41:37.114647       1 event.go:294] "Event occurred" object="azuredisk-9183/pvc-azuredisk-volume-tester-89tzd-0" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
I0907 13:41:37.114712       1 event.go:294] "Event occurred" object="azuredisk-9183/pvc-azuredisk-volume-tester-89tzd-0" kind="PersistentVolumeClaim" apiVersion="v1" type="Normal" reason="ExternalProvisioning" message="waiting for a volume to be created, either by external provisioner \"disk.csi.azure.com\" or manually created by system administrator"
... skipping 20 lines ...
I0907 13:42:19.165622       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:19.165638       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:29.165762       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:29.165796       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:29.165803       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:33.806408       1 event.go:294] "Event occurred" object="azuredisk-9183/azuredisk-volume-tester-89tzd" kind="StatefulSet" apiVersion="apps/v1" type="Normal" reason="SuccessfulCreate" message="create Pod azuredisk-volume-tester-89tzd-0 in StatefulSet azuredisk-volume-tester-89tzd successful"
I0907 13:42:33.869863       1 event.go:294] "Event occurred" object="azuredisk-9183/azuredisk-volume-tester-89tzd-0" kind="Pod" apiVersion="v1" type="Warning" reason="FailedAttachVolume" message="Multi-Attach error for volume \"pvc-774df78a-e544-430b-a352-25e33ebf1510\" Volume is already exclusively attached to one node and can't be attached to another"
W0907 13:42:33.869894       1 reconciler.go:344] Multi-Attach error for volume "pvc-774df78a-e544-430b-a352-25e33ebf1510" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-774df78a-e544-430b-a352-25e33ebf1510") from node "k8s-agentpool1-39118761-0" Volume is already exclusively attached to node k8s-agentpool1-39118761-1 and can't be attached to another
I0907 13:42:37.600032       1 reconciler.go:221] attacherDetacher.DetachVolume started for volume "pvc-774df78a-e544-430b-a352-25e33ebf1510" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-774df78a-e544-430b-a352-25e33ebf1510") on node "k8s-agentpool1-39118761-1" 
I0907 13:42:37.602217       1 operation_generator.go:1641] Verified volume is safe to detach for volume "pvc-774df78a-e544-430b-a352-25e33ebf1510" (UniqueName: "kubernetes.io/csi/disk.csi.azure.com^/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-774df78a-e544-430b-a352-25e33ebf1510") on node "k8s-agentpool1-39118761-1" 
I0907 13:42:39.166232       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:39.166265       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:39.166342       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:42:49.166582       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
... skipping 17 lines ...
I0907 13:43:10.851842       1 garbagecollector.go:580] "Deleting object" object="azuredisk-9183/azuredisk-volume-tester-89tzd-7dc4c9c847" objectUID=cac53772-7b3a-4259-9433-b10aa3051221 kind="ControllerRevision" propagationPolicy=Background
I0907 13:43:16.532897       1 pvc_protection_controller.go:281] "Pod uses PVC" pod="azuredisk-9183/azuredisk-volume-tester-89tzd-0" PVC="azuredisk-9183/pvc-azuredisk-volume-tester-89tzd-0"
I0907 13:43:16.532923       1 pvc_protection_controller.go:174] "Keeping PVC because it is being used" PVC="azuredisk-9183/pvc-azuredisk-volume-tester-89tzd-0"
I0907 13:43:19.169170       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:43:19.169334       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:43:19.169406       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
E0907 13:43:22.197156       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-4415/default: secrets "default-token-tf2qd" is forbidden: unable to create new content in namespace azuredisk-4415 because it is being terminated
E0907 13:43:23.173702       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-6720/default: secrets "default-token-vxgth" is forbidden: unable to create new content in namespace azuredisk-6720 because it is being terminated
I0907 13:43:23.426642       1 namespace_controller.go:185] Namespace has been deleted azuredisk-8154
E0907 13:43:25.098280       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-6200/default: secrets "default-token-hpmg6" is forbidden: unable to create new content in namespace azuredisk-6200 because it is being terminated
I0907 13:43:25.341852       1 namespace_controller.go:185] Namespace has been deleted azuredisk-1166
E0907 13:43:27.067629       1 tokens_controller.go:262] error synchronizing serviceaccount azuredisk-9103/default: secrets "default-token-kdvvg" is forbidden: unable to create new content in namespace azuredisk-9103 because it is being terminated
I0907 13:43:27.255239       1 namespace_controller.go:185] Namespace has been deleted azuredisk-4415
I0907 13:43:28.247459       1 namespace_controller.go:185] Namespace has been deleted azuredisk-6720
I0907 13:43:29.170049       1 route_controller.go:299] set node k8s-agentpool1-39118761-1 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:43:29.170068       1 route_controller.go:299] set node k8s-agentpool1-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:43:29.170055       1 route_controller.go:299] set node k8s-master-39118761-0 with NodeNetworkUnavailable=false was canceled because it is already set
I0907 13:43:29.267014       1 namespace_controller.go:185] Namespace has been deleted azuredisk-4162
... skipping 91 lines ...
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0907 13:22:40.645519       1 azuredisk.go:172] driver userAgent: disk.csi.azure.com/v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 e2e-test
I0907 13:22:40.645801       1 azure_disk_utils.go:159] reading cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:40.663404       1 azure_disk_utils.go:166] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0907 13:22:40.663421       1 azure_disk_utils.go:171] could not read cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:40.663426       1 azure_disk_utils.go:181] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0907 13:22:40.663443       1 azure_disk_utils.go:189] read cloud config from file: /etc/kubernetes/azure.json successfully
I0907 13:22:40.663943       1 azure_auth.go:245] Using AzurePublicCloud environment
I0907 13:22:40.663977       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0907 13:22:40.663996       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 98 lines ...
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0907 13:22:39.601199       1 azuredisk.go:172] driver userAgent: disk.csi.azure.com/v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 e2e-test
I0907 13:22:39.601494       1 azure_disk_utils.go:159] reading cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:39.626134       1 azure_disk_utils.go:166] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0907 13:22:39.626149       1 azure_disk_utils.go:171] could not read cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:39.626155       1 azure_disk_utils.go:181] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0907 13:22:39.626174       1 azure_disk_utils.go:189] read cloud config from file: /etc/kubernetes/azure.json successfully
I0907 13:22:39.626707       1 azure_auth.go:245] Using AzurePublicCloud environment
I0907 13:22:39.626741       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0907 13:22:39.626757       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 974 lines ...
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0907 13:22:34.787947       1 azuredisk.go:172] driver userAgent: disk.csi.azure.com/v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 e2e-test
I0907 13:22:34.788520       1 azure_disk_utils.go:159] reading cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:34.810293       1 azure_disk_utils.go:166] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0907 13:22:34.810315       1 azure_disk_utils.go:171] could not read cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:34.810321       1 azure_disk_utils.go:181] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0907 13:22:34.810340       1 azure_disk_utils.go:189] read cloud config from file: /etc/kubernetes/azure.json successfully
I0907 13:22:34.810869       1 azure_auth.go:245] Using AzurePublicCloud environment
I0907 13:22:34.810905       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0907 13:22:34.810938       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 505 lines ...
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0907 13:22:35.363650       1 azuredisk.go:172] driver userAgent: disk.csi.azure.com/v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 e2e-test
I0907 13:22:35.363968       1 azure_disk_utils.go:159] reading cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:35.383872       1 azure_disk_utils.go:166] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0907 13:22:35.383888       1 azure_disk_utils.go:171] could not read cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:35.383893       1 azure_disk_utils.go:181] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0907 13:22:35.383909       1 azure_disk_utils.go:189] read cloud config from file: /etc/kubernetes/azure.json successfully
I0907 13:22:35.384449       1 azure_auth.go:245] Using AzurePublicCloud environment
I0907 13:22:35.384484       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0907 13:22:35.384501       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 104 lines ...
I0907 13:24:09.233832       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:09.242487       1 mount_linux.go:490] Output: ""
I0907 13:24:09.242509       1 mount_linux.go:449] Disk "/dev/disk/azure/scsi1/lun0" appears to be unformatted, attempting to format as type: "ext4" with options: [-F -m0 /dev/disk/azure/scsi1/lun0]
I0907 13:24:10.123743       1 mount_linux.go:459] Disk successfully formatted (mkfs): ext4 - /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:10.123770       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:10.123787       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:10.129355       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:10.129406       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:10.687273       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:10.687290       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:12.297153       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:12.297180       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:12.297644       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:12.297664       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:12.303055       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:12.303076       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:12.314228       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:12.314275       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:12.319834       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:12.319863       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:13.408446       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:13.408465       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:14.999233       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:14.999263       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:14.999564       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:14.999582       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:15.004971       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:15.005001       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:15.016818       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:15.016841       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:15.021856       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:15.021884       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:17.134191       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:17.134210       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:18.732037       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:18.732252       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:18.732542       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:18.732561       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:18.739362       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:18.739380       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:18.754614       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:18.754643       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:18.759813       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:18.759839       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:22.770476       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:22.770493       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:24.350503       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:24.350529       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:24.350865       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:24.350901       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:24.356219       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:24.356239       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:24.369343       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:24.369366       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:24.374839       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:24.375003       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:32.447675       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:32.447693       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:34.015320       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:34.015349       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:34.015696       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:34.015723       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:34.021529       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:34.021547       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:34.031695       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:34.031724       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:34.038264       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:34.038417       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:24:50.089128       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:24:50.089146       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:24:51.653382       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:24:51.653408       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:24:51.653828       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:24:51.653849       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:24:51.658643       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:24:51.658664       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:24:51.669200       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:24:51.669227       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:24:51.674213       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:24:51.674243       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:25:23.761044       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:25:23.761060       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"500","diskmbpsreadwrite":"60","networkaccesspolicy":"AllowAll","skuname":"StandardSSD_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount","volume_capability":{"AccessType":{"Mount":{"mount_flags":["invalid","mount","options"]}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace"}
I0907 13:25:25.340587       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:25:25.340610       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:25:25.340842       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount with mount options([invalid mount options])
I0907 13:25:25.340856       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
I0907 13:25:25.364311       1 mount_linux.go:490] Output: "DEVNAME=/dev/disk/azure/scsi1/lun0\nTYPE=ext4\n"
I0907 13:25:25.364331       1 mount_linux.go:376] Checking for issues with fsck on disk: /dev/disk/azure/scsi1/lun0
I0907 13:25:25.379330       1 mount_linux.go:477] Attempting to mount disk /dev/disk/azure/scsi1/lun0 in ext4 format at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
I0907 13:25:25.379357       1 mount_linux.go:183] Mounting cmd (mount) with arguments (-t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount)
E0907 13:25:25.385381       1 mount_linux.go:195] Mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.

E0907 13:25:25.385409       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun0(lun: 0), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount, failed with mount failed: exit status 32
Mounting command: mount
Mounting arguments: -t ext4 -o invalid,mount,options,defaults /dev/disk/azure/scsi1/lun0 /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount
Output: mount: /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-4b6f62ee-a3de-43b7-999b-9577bf25dace/globalmount: wrong fs type, bad option, bad superblock on /dev/sdc, missing codepage or helper program, or other error.
I0907 13:28:50.218925       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0907 13:28:50.218943       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"0","diskiopsreadwrite":"120","diskmbpsreadwrite":"25","networkaccesspolicy":"AllowAll","skuname":"Premium_LRS"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-291aa8de-48ee-4544-a735-5dfdd4af4c27/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"cachingmode":"ReadWrite","fstype":"","kind":"Managed"},"volume_id":"/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-ttcndx8r/providers/Microsoft.Compute/disks/pvc-291aa8de-48ee-4544-a735-5dfdd4af4c27"}
I0907 13:28:51.831848       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun0 by sdc under /dev/disk/azure/scsi1/
I0907 13:28:51.831873       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun0. perfProfile none accountType 
I0907 13:28:51.832291       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun0 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-291aa8de-48ee-4544-a735-5dfdd4af4c27/globalmount with mount options([])
I0907 13:28:51.832302       1 mount_linux.go:487] Attempting to determine if disk "/dev/disk/azure/scsi1/lun0" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun0])
... skipping 397 lines ...
Platform: linux/amd64
Topology Key: topology.disk.csi.azure.com/zone

Streaming logs below:
I0907 13:22:31.518753       1 azuredisk.go:172] driver userAgent: disk.csi.azure.com/v1.23.0-b4185f24ea9ea8f4bed011477782f7a7aa32d1c4 e2e-test
I0907 13:22:31.519176       1 azure_disk_utils.go:159] reading cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:31.543644       1 azure_disk_utils.go:166] InitializeCloudFromSecret: failed to get cloud config from secret kube-system/azure-cloud-provider: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
I0907 13:22:31.543666       1 azure_disk_utils.go:171] could not read cloud config from secret kube-system/azure-cloud-provider
I0907 13:22:31.543672       1 azure_disk_utils.go:181] use default AZURE_CREDENTIAL_FILE env var: /etc/kubernetes/azure.json
I0907 13:22:31.543700       1 azure_disk_utils.go:189] read cloud config from file: /etc/kubernetes/azure.json successfully
I0907 13:22:31.544286       1 azure_auth.go:245] Using AzurePublicCloud environment
I0907 13:22:31.544324       1 azure_auth.go:130] azure: using client_id+client_secret to retrieve access token
I0907 13:22:31.544355       1 azure.go:774] Azure cloudprovider using try backoff: retries=6, exponent=1.500000, duration=5, jitter=1.000000
... skipping 512 lines ...
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
2022/09/07 13:45:45 Azure Disk CSI Driver uninstalled

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

Ran 13 of 59 Specs in 1956.729 seconds
SUCCESS! -- 13 Passed | 0 Failed | 0 Pending | 46 Skipped

You're using deprecated Ginkgo functionality:
=============================================
Ginkgo 2.0 is under active development and will introduce several new features, improvements, and a small handful of breaking changes.
A release candidate for 2.0 is now available and 2.0 should GA in Fall 2021.  Please give the RC a try and send us feedback!
  - To learn more, view the migration guide at https://github.com/onsi/ginkgo/blob/ver2/docs/MIGRATING_TO_V2.md
... skipping 89 lines ...