This job view page is being replaced by Spyglass soon. Check out the new job view.
PRhccheng72: [V2] fix: prevent requesting replica attachment in a row for one volume
ResultABORTED
Tests 0 failed / 0 succeeded
Started2023-01-17 17:54
Elapsed46m33s
Revisionac3d54e32c4e8daecb77c0bdd5dd97729c353957
Refs 1693

No Test Failures!


Error lines from build-log.txt

... skipping 100 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11345  100 11345    0     0   184k      0 --:--:-- --:--:-- --:--:--  184k
Downloading https://get.helm.sh/helm-v3.10.3-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:latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azuredisk-csi:latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc not found: manifest unknown: manifest tagged by "latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc" 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=latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=75eecb5c876f7e33167f6048a2d9266d5626d5cc -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2023-01-17T18:01:21Z -extldflags "-static"" -tags azurediskv2 -mod vendor -o _output/amd64/azurediskpluginv2.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 679 lines ...
         }
      }
   ]
}
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
docker pull k8sprow.azurecr.io/azdiskschedulerextender-csi:latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc || make azdiskschedulerextender-all push-manifest-azdiskschedulerextender
Error response from daemon: manifest for k8sprow.azurecr.io/azdiskschedulerextender-csi:latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc not found: manifest unknown: manifest tagged by "latest-v2-75eecb5c876f7e33167f6048a2d9266d5626d5cc" is not found
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver'
docker buildx rm container-builder || true
container-builder removed
docker buildx create --use --name=container-builder
container-builder
# enable qemu for arm64 build
... skipping 1069 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 occurs 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 occurs 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 359 lines ...
            - volumeName
            - volume_context
            - volume_id
            type: object
          status:
            description: status represents the current state of AzVolumeAttachment.
              includes error, state, and attachment status Required
            properties:
              detail:
                description: Status summarizes the current attachment state of the
                  volume attachment Nil Status indicates that the volume has not yet
                  been attached to the node
                properties:
... skipping 7 lines ...
                  role:
                    description: The current attachment role.
                    type: string
                required:
                - role
                type: object
              error:
                description: Error occurred during attach/detach of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 90 lines ...
            - volumeName
            - volume_context
            - volume_id
            type: object
          status:
            description: status represents the current state of AzVolumeAttachment.
              includes error, state, and attachment status
            properties:
              annotation:
                additionalProperties:
                  type: string
                description: Annotations contains additional resource information
                  to guide driver actions
... skipping 13 lines ...
                  role:
                    description: The current attachment role.
                    type: string
                required:
                - role
                type: object
              error:
                description: Error occurred during attach/detach of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 169 lines ...
            - maxMountReplicaCount
            - volumeCapability
            - volumeName
            type: object
          status:
            description: status represents the current state of AzVolume. includes
              error, state, and volume status
            properties:
              detail:
                description: Current status detail of the AzVolume Nil detail indicates
                  that the volume has not been created
                properties:
                  accessible_topology:
... skipping 28 lines ...
                    type: string
                required:
                - capacity_bytes
                - node_expansion_required
                - volume_id
                type: object
              error:
                description: Error occurred during creation/deletion of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 154 lines ...
            - maxMountReplicaCount
            - volumeCapability
            - volumeName
            type: object
          status:
            description: status represents the current state of AzVolume. includes
              error, state, and volume status
            properties:
              annotation:
                additionalProperties:
                  type: string
                description: Annotations contains additional resource information
                  to guide driver actions
... skipping 34 lines ...
                    type: string
                required:
                - capacity_bytes
                - node_expansion_required
                - volume_id
                type: object
              error:
                description: Error occurred during creation/deletion of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 883 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 327 lines ...
Jan 17 18:11:31.494: INFO: PersistentVolumeClaim pvc-bgtnp found but phase is Pending instead of Bound.
Jan 17 18:11:33.530: INFO: PersistentVolumeClaim pvc-bgtnp found and phase=Bound (6.146453345s)
STEP: checking the PVC 01/17/23 18:11:33.53
STEP: validating provisioned PV 01/17/23 18:11:33.566
STEP: checking the PV 01/17/23 18:11:33.601
STEP: deploying the pod 01/17/23 18:11:33.601
STEP: checking that the pod's command exits with an error 01/17/23 18:11:33.648
Jan 17 18:11:33.648: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-9d8g2" in namespace "azuredisk-9777" to be "Error status code"
Jan 17 18:11:33.700: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 52.121726ms
Jan 17 18:11:35.737: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.088683815s
Jan 17 18:11:37.746: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.097793078s
Jan 17 18:11:39.737: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.088714785s
Jan 17 18:11:41.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089742213s
Jan 17 18:11:43.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.090105345s
... skipping 21 lines ...
Jan 17 18:12:27.736: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 54.087986551s
Jan 17 18:12:29.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 56.090495508s
Jan 17 18:12:31.740: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 58.091373818s
Jan 17 18:12:33.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 1m0.089412356s
Jan 17 18:12:35.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=false. Elapsed: 1m2.090453326s
Jan 17 18:12:37.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.090798641s
Jan 17 18:12:39.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Failed", Reason="", readiness=false. Elapsed: 1m6.089987859s
STEP: Saw pod failure 01/17/23 18:12:39.738
Jan 17 18:12:39.739: INFO: Pod "azuredisk-volume-tester-9d8g2" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message 01/17/23 18:12:39.739
Jan 17 18:12:39.810: INFO: deleting Pod "azuredisk-9777"/"azuredisk-volume-tester-9d8g2"
Jan 17 18:12:39.850: INFO: Pod azuredisk-volume-tester-9d8g2 has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied.
At line:1 char:22
+ ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ...
+                         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 58 lines ...
    Jan 17 18:11:31.494: INFO: PersistentVolumeClaim pvc-bgtnp found but phase is Pending instead of Bound.
    Jan 17 18:11:33.530: INFO: PersistentVolumeClaim pvc-bgtnp found and phase=Bound (6.146453345s)
    STEP: checking the PVC 01/17/23 18:11:33.53
    STEP: validating provisioned PV 01/17/23 18:11:33.566
    STEP: checking the PV 01/17/23 18:11:33.601
    STEP: deploying the pod 01/17/23 18:11:33.601
    STEP: checking that the pod's command exits with an error 01/17/23 18:11:33.648
    Jan 17 18:11:33.648: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-9d8g2" in namespace "azuredisk-9777" to be "Error status code"
    Jan 17 18:11:33.700: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 52.121726ms
    Jan 17 18:11:35.737: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.088683815s
    Jan 17 18:11:37.746: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.097793078s
    Jan 17 18:11:39.737: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.088714785s
    Jan 17 18:11:41.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089742213s
    Jan 17 18:11:43.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.090105345s
... skipping 21 lines ...
    Jan 17 18:12:27.736: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 54.087986551s
    Jan 17 18:12:29.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 56.090495508s
    Jan 17 18:12:31.740: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 58.091373818s
    Jan 17 18:12:33.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=true. Elapsed: 1m0.089412356s
    Jan 17 18:12:35.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=false. Elapsed: 1m2.090453326s
    Jan 17 18:12:37.739: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.090798641s
    Jan 17 18:12:39.738: INFO: Pod "azuredisk-volume-tester-9d8g2": Phase="Failed", Reason="", readiness=false. Elapsed: 1m6.089987859s
    STEP: Saw pod failure 01/17/23 18:12:39.738
    Jan 17 18:12:39.739: INFO: Pod "azuredisk-volume-tester-9d8g2" satisfied condition "Error status code"
    STEP: checking that pod logs contain expected message 01/17/23 18:12:39.739
    Jan 17 18:12:39.810: INFO: deleting Pod "azuredisk-9777"/"azuredisk-volume-tester-9d8g2"
    Jan 17 18:12:39.850: INFO: Pod azuredisk-volume-tester-9d8g2 has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied.
    At line:1 char:22
    + ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ...
    +                         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 85 lines ...
Jan 17 18:13:27.559: INFO: PersistentVolumeClaim pvc-2kk2g found and phase=Bound (2.073609329s)
STEP: checking the PVC 01/17/23 18:13:27.56
STEP: validating provisioned PV 01/17/23 18:13:27.595
STEP: checking the PV 01/17/23 18:13:27.644
STEP: attaching disk to node#0 01/17/23 18:13:27.682
STEP: deploying the pod 01/17/23 18:13:34.857
STEP: checking that the pod's command exits with no error 01/17/23 18:13:34.897
Jan 17 18:13:34.897: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fcsg4" in namespace "azuredisk-3196" to be "Succeeded or Failed"
Jan 17 18:13:34.946: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 49.149749ms
Jan 17 18:13:36.983: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.085894466s
Jan 17 18:13:38.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087085372s
Jan 17 18:13:40.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.087396172s
Jan 17 18:13:42.990: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.092769172s
Jan 17 18:13:44.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.086723966s
... skipping 20 lines ...
Jan 17 18:14:26.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=true. Elapsed: 52.087035447s
Jan 17 18:14:28.985: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=true. Elapsed: 54.087906768s
Jan 17 18:14:30.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=false. Elapsed: 56.086678139s
Jan 17 18:14:32.985: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=false. Elapsed: 58.087847529s
Jan 17 18:14:34.983: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m0.08640432s
STEP: Saw pod success 01/17/23 18:14:34.984
Jan 17 18:14:34.984: INFO: Pod "azuredisk-volume-tester-fcsg4" satisfied condition "Succeeded or Failed"
Jan 17 18:14:34.984: INFO: deleting Pod "azuredisk-3196"/"azuredisk-volume-tester-fcsg4"
Jan 17 18:14:35.046: INFO: Pod azuredisk-volume-tester-fcsg4 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-fcsg4 in namespace azuredisk-3196 01/17/23 18:14:35.047
Jan 17 18:14:35.186: INFO: deleting PVC "azuredisk-3196"/"pvc-2kk2g"
Jan 17 18:14:35.187: INFO: Deleting PersistentVolumeClaim "pvc-2kk2g"
... skipping 37 lines ...
    Jan 17 18:13:27.559: INFO: PersistentVolumeClaim pvc-2kk2g found and phase=Bound (2.073609329s)
    STEP: checking the PVC 01/17/23 18:13:27.56
    STEP: validating provisioned PV 01/17/23 18:13:27.595
    STEP: checking the PV 01/17/23 18:13:27.644
    STEP: attaching disk to node#0 01/17/23 18:13:27.682
    STEP: deploying the pod 01/17/23 18:13:34.857
    STEP: checking that the pod's command exits with no error 01/17/23 18:13:34.897
    Jan 17 18:13:34.897: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fcsg4" in namespace "azuredisk-3196" to be "Succeeded or Failed"
    Jan 17 18:13:34.946: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 49.149749ms
    Jan 17 18:13:36.983: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.085894466s
    Jan 17 18:13:38.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.087085372s
    Jan 17 18:13:40.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.087396172s
    Jan 17 18:13:42.990: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.092769172s
    Jan 17 18:13:44.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.086723966s
... skipping 20 lines ...
    Jan 17 18:14:26.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=true. Elapsed: 52.087035447s
    Jan 17 18:14:28.985: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=true. Elapsed: 54.087906768s
    Jan 17 18:14:30.984: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=false. Elapsed: 56.086678139s
    Jan 17 18:14:32.985: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Running", Reason="", readiness=false. Elapsed: 58.087847529s
    Jan 17 18:14:34.983: INFO: Pod "azuredisk-volume-tester-fcsg4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m0.08640432s
    STEP: Saw pod success 01/17/23 18:14:34.984
    Jan 17 18:14:34.984: INFO: Pod "azuredisk-volume-tester-fcsg4" satisfied condition "Succeeded or Failed"
    Jan 17 18:14:34.984: INFO: deleting Pod "azuredisk-3196"/"azuredisk-volume-tester-fcsg4"
    Jan 17 18:14:35.046: INFO: Pod azuredisk-volume-tester-fcsg4 has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-fcsg4 in namespace azuredisk-3196 01/17/23 18:14:35.047
    Jan 17 18:14:35.186: INFO: deleting PVC "azuredisk-3196"/"pvc-2kk2g"
    Jan 17 18:14:35.187: INFO: Deleting PersistentVolumeClaim "pvc-2kk2g"
... skipping 151 lines ...
  << End Captured GinkgoWriter Output

  test case not supported by Windows clusters
  In [It] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/utils/testutil/env_utils.go:26

  There were additional failures detected after the initial failure:
    [FAILED]
    pre-provisioning disk got deleted with the deletion of pv: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {
      "error": {

        "code": "NotFound",
        "message": "Disk single-shared-disk is not found."
      }
    }
    In [AfterEach] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:490
------------------------------
... skipping 27 lines ...
  << End Captured GinkgoWriter Output

  test case not supported by Windows clusters
  In [It] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/utils/testutil/env_utils.go:26

  There were additional failures detected after the initial failure:
    [FAILED]
    pre-provisioning disk got deleted with the deletion of pv: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {
      "error": {

        "code": "NotFound",
        "message": "Disk single-shared-disk is not found."
      }
    }
    In [AfterEach] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:490
------------------------------
... skipping 27 lines ...
  << End Captured GinkgoWriter Output

  test case is only available for csi driver
  In [It] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:395

  There were additional failures detected after the initial failure:
    [FAILED]
    pre-provisioning disk got deleted with the deletion of pv: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: {
      "error": {

        "code": "NotFound",
        "message": "Disk single-shared-disk is not found."
      }
    }
    In [AfterEach] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:490
------------------------------
... skipping 22 lines ...
STEP: checking the PVC 01/17/23 18:15:27.283
STEP: validating provisioned PV 01/17/23 18:15:27.319
STEP: checking the PV 01/17/23 18:15:27.354
STEP: setting up the pod 01/17/23 18:15:27.354
I0117 18:15:27.355032   15886 resource_setup.go:62] adding PV (pvc-6ea9b5fe-496e-4514-8731-1d321d4a62ab) to pod ()
STEP: deploying the pod 01/17/23 18:15:27.355
STEP: checking that the pod's command exits with no error 01/17/23 18:15:27.399
Jan 17 18:15:27.399: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-jvf96" in namespace "azuredisk-3231" to be "Succeeded or Failed"
Jan 17 18:15:27.446: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 46.621401ms
Jan 17 18:15:29.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 2.084339166s
Jan 17 18:15:31.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 4.084686958s
Jan 17 18:15:33.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 6.085047071s
Jan 17 18:15:35.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 8.08432535s
Jan 17 18:15:37.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 10.084599754s
... skipping 17 lines ...
Jan 17 18:16:13.494: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=true. Elapsed: 46.094950491s
Jan 17 18:16:15.483: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=true. Elapsed: 48.083251202s
Jan 17 18:16:17.489: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=false. Elapsed: 50.0899127s
Jan 17 18:16:19.482: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=false. Elapsed: 52.082948723s
Jan 17 18:16:21.483: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Succeeded", Reason="", readiness=false. Elapsed: 54.083944801s
STEP: Saw pod success 01/17/23 18:16:21.483
Jan 17 18:16:21.483: INFO: Pod "azuredisk-volume-tester-jvf96" satisfied condition "Succeeded or Failed"
Jan 17 18:16:21.483: INFO: deleting Pod "azuredisk-3231"/"azuredisk-volume-tester-jvf96"
Jan 17 18:16:21.552: INFO: Pod azuredisk-volume-tester-jvf96 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-jvf96 in namespace azuredisk-3231 01/17/23 18:16:21.552
Jan 17 18:16:21.621: INFO: deleting PVC "azuredisk-3231"/"pvc-lkwmh"
Jan 17 18:16:21.621: INFO: Deleting PersistentVolumeClaim "pvc-lkwmh"
... skipping 40 lines ...
    STEP: checking the PVC 01/17/23 18:15:27.283
    STEP: validating provisioned PV 01/17/23 18:15:27.319
    STEP: checking the PV 01/17/23 18:15:27.354
    STEP: setting up the pod 01/17/23 18:15:27.354
    I0117 18:15:27.355032   15886 resource_setup.go:62] adding PV (pvc-6ea9b5fe-496e-4514-8731-1d321d4a62ab) to pod ()
    STEP: deploying the pod 01/17/23 18:15:27.355
    STEP: checking that the pod's command exits with no error 01/17/23 18:15:27.399
    Jan 17 18:15:27.399: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-jvf96" in namespace "azuredisk-3231" to be "Succeeded or Failed"
    Jan 17 18:15:27.446: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 46.621401ms
    Jan 17 18:15:29.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 2.084339166s
    Jan 17 18:15:31.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 4.084686958s
    Jan 17 18:15:33.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 6.085047071s
    Jan 17 18:15:35.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 8.08432535s
    Jan 17 18:15:37.484: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Pending", Reason="", readiness=false. Elapsed: 10.084599754s
... skipping 17 lines ...
    Jan 17 18:16:13.494: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=true. Elapsed: 46.094950491s
    Jan 17 18:16:15.483: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=true. Elapsed: 48.083251202s
    Jan 17 18:16:17.489: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=false. Elapsed: 50.0899127s
    Jan 17 18:16:19.482: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Running", Reason="", readiness=false. Elapsed: 52.082948723s
    Jan 17 18:16:21.483: INFO: Pod "azuredisk-volume-tester-jvf96": Phase="Succeeded", Reason="", readiness=false. Elapsed: 54.083944801s
    STEP: Saw pod success 01/17/23 18:16:21.483
    Jan 17 18:16:21.483: INFO: Pod "azuredisk-volume-tester-jvf96" satisfied condition "Succeeded or Failed"
    Jan 17 18:16:21.483: INFO: deleting Pod "azuredisk-3231"/"azuredisk-volume-tester-jvf96"
    Jan 17 18:16:21.552: INFO: Pod azuredisk-volume-tester-jvf96 has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-jvf96 in namespace azuredisk-3231 01/17/23 18:16:21.552
    Jan 17 18:16:21.621: INFO: deleting PVC "azuredisk-3231"/"pvc-lkwmh"
    Jan 17 18:16:21.621: INFO: Deleting PersistentVolumeClaim "pvc-lkwmh"
... skipping 37 lines ...
Jan 17 18:17:04.899: INFO: PersistentVolumeClaim pvc-jwnqf found but phase is Pending instead of Bound.
Jan 17 18:17:06.937: INFO: PersistentVolumeClaim pvc-jwnqf found and phase=Bound (4.125233222s)
STEP: checking the PVC 01/17/23 18:17:06.937
STEP: validating provisioned PV 01/17/23 18:17:06.973
STEP: checking the PV 01/17/23 18:17:07.013
STEP: deploying the pod 01/17/23 18:17:07.013
STEP: checking that the pods command exits with no error 01/17/23 18:17:07.051
Jan 17 18:17:07.051: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-msdhl" in namespace "azuredisk-7258" to be "Succeeded or Failed"
Jan 17 18:17:07.096: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 45.112084ms
Jan 17 18:17:09.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081626581s
Jan 17 18:17:11.132: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.081473743s
Jan 17 18:17:13.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.082216185s
Jan 17 18:17:15.141: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089686268s
Jan 17 18:17:17.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.083249935s
... skipping 14 lines ...
Jan 17 18:17:47.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=true. Elapsed: 40.082603449s
Jan 17 18:17:49.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=true. Elapsed: 42.08202854s
Jan 17 18:17:51.143: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=false. Elapsed: 44.091612411s
Jan 17 18:17:53.132: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=false. Elapsed: 46.081335911s
Jan 17 18:17:55.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 48.082933804s
STEP: Saw pod success 01/17/23 18:17:55.134
Jan 17 18:17:55.134: INFO: Pod "azuredisk-volume-tester-msdhl" satisfied condition "Succeeded or Failed"
Jan 17 18:17:55.134: INFO: deleting Pod "azuredisk-7258"/"azuredisk-volume-tester-msdhl"
Jan 17 18:17:55.209: INFO: Pod azuredisk-volume-tester-msdhl has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-msdhl in namespace azuredisk-7258 01/17/23 18:17:55.209
Jan 17 18:17:55.263: INFO: deleting PVC "azuredisk-7258"/"pvc-jwnqf"
Jan 17 18:17:55.263: INFO: Deleting PersistentVolumeClaim "pvc-jwnqf"
... skipping 38 lines ...
    Jan 17 18:17:04.899: INFO: PersistentVolumeClaim pvc-jwnqf found but phase is Pending instead of Bound.
    Jan 17 18:17:06.937: INFO: PersistentVolumeClaim pvc-jwnqf found and phase=Bound (4.125233222s)
    STEP: checking the PVC 01/17/23 18:17:06.937
    STEP: validating provisioned PV 01/17/23 18:17:06.973
    STEP: checking the PV 01/17/23 18:17:07.013
    STEP: deploying the pod 01/17/23 18:17:07.013
    STEP: checking that the pods command exits with no error 01/17/23 18:17:07.051
    Jan 17 18:17:07.051: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-msdhl" in namespace "azuredisk-7258" to be "Succeeded or Failed"
    Jan 17 18:17:07.096: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 45.112084ms
    Jan 17 18:17:09.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081626581s
    Jan 17 18:17:11.132: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.081473743s
    Jan 17 18:17:13.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.082216185s
    Jan 17 18:17:15.141: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089686268s
    Jan 17 18:17:17.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.083249935s
... skipping 14 lines ...
    Jan 17 18:17:47.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=true. Elapsed: 40.082603449s
    Jan 17 18:17:49.133: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=true. Elapsed: 42.08202854s
    Jan 17 18:17:51.143: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=false. Elapsed: 44.091612411s
    Jan 17 18:17:53.132: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Running", Reason="", readiness=false. Elapsed: 46.081335911s
    Jan 17 18:17:55.134: INFO: Pod "azuredisk-volume-tester-msdhl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 48.082933804s
    STEP: Saw pod success 01/17/23 18:17:55.134
    Jan 17 18:17:55.134: INFO: Pod "azuredisk-volume-tester-msdhl" satisfied condition "Succeeded or Failed"
    Jan 17 18:17:55.134: INFO: deleting Pod "azuredisk-7258"/"azuredisk-volume-tester-msdhl"
    Jan 17 18:17:55.209: INFO: Pod azuredisk-volume-tester-msdhl has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-msdhl in namespace azuredisk-7258 01/17/23 18:17:55.209
    Jan 17 18:17:55.263: INFO: deleting PVC "azuredisk-7258"/"pvc-jwnqf"
    Jan 17 18:17:55.263: INFO: Deleting PersistentVolumeClaim "pvc-jwnqf"
... skipping 39 lines ...
STEP: checking the PVC 01/17/23 18:18:40.639
STEP: validating provisioned PV 01/17/23 18:18:40.674
STEP: checking the PV 01/17/23 18:18:40.709
STEP: setting up the pod 01/17/23 18:18:40.71
I0117 18:18:40.710195   15886 resource_setup.go:62] adding PV (pvc-7364239e-9c6b-417c-ae38-1c30048b5d8d) to pod ()
STEP: deploying the pod 01/17/23 18:18:40.71
STEP: checking that the pod's command exits with no error 01/17/23 18:18:40.75
Jan 17 18:18:40.751: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5jhlt" in namespace "azuredisk-7089" to be "Succeeded or Failed"
Jan 17 18:18:40.792: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 41.477308ms
Jan 17 18:18:42.829: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.077978562s
Jan 17 18:18:44.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.079616587s
Jan 17 18:18:46.828: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.077724385s
Jan 17 18:18:48.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.079672789s
Jan 17 18:18:50.831: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.080585075s
... skipping 15 lines ...
Jan 17 18:19:22.829: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=true. Elapsed: 42.078616416s
Jan 17 18:19:24.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 44.079221506s
Jan 17 18:19:26.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 46.079720667s
Jan 17 18:19:28.832: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 48.081726662s
Jan 17 18:19:30.831: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.080697257s
STEP: Saw pod success 01/17/23 18:19:30.831
Jan 17 18:19:30.832: INFO: Pod "azuredisk-volume-tester-5jhlt" satisfied condition "Succeeded or Failed"
Jan 17 18:19:30.832: INFO: deleting Pod "azuredisk-7089"/"azuredisk-volume-tester-5jhlt"
Jan 17 18:19:30.897: INFO: Pod azuredisk-volume-tester-5jhlt has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-5jhlt in namespace azuredisk-7089 01/17/23 18:19:30.897
Jan 17 18:19:30.941: INFO: deleting PVC "azuredisk-7089"/"pvc-vkvrd"
Jan 17 18:19:30.941: INFO: Deleting PersistentVolumeClaim "pvc-vkvrd"
... skipping 40 lines ...
    STEP: checking the PVC 01/17/23 18:18:40.639
    STEP: validating provisioned PV 01/17/23 18:18:40.674
    STEP: checking the PV 01/17/23 18:18:40.709
    STEP: setting up the pod 01/17/23 18:18:40.71
    I0117 18:18:40.710195   15886 resource_setup.go:62] adding PV (pvc-7364239e-9c6b-417c-ae38-1c30048b5d8d) to pod ()
    STEP: deploying the pod 01/17/23 18:18:40.71
    STEP: checking that the pod's command exits with no error 01/17/23 18:18:40.75
    Jan 17 18:18:40.751: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5jhlt" in namespace "azuredisk-7089" to be "Succeeded or Failed"
    Jan 17 18:18:40.792: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 41.477308ms
    Jan 17 18:18:42.829: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.077978562s
    Jan 17 18:18:44.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.079616587s
    Jan 17 18:18:46.828: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.077724385s
    Jan 17 18:18:48.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.079672789s
    Jan 17 18:18:50.831: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.080585075s
... skipping 15 lines ...
    Jan 17 18:19:22.829: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=true. Elapsed: 42.078616416s
    Jan 17 18:19:24.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 44.079221506s
    Jan 17 18:19:26.830: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 46.079720667s
    Jan 17 18:19:28.832: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Running", Reason="", readiness=false. Elapsed: 48.081726662s
    Jan 17 18:19:30.831: INFO: Pod "azuredisk-volume-tester-5jhlt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.080697257s
    STEP: Saw pod success 01/17/23 18:19:30.831
    Jan 17 18:19:30.832: INFO: Pod "azuredisk-volume-tester-5jhlt" satisfied condition "Succeeded or Failed"
    Jan 17 18:19:30.832: INFO: deleting Pod "azuredisk-7089"/"azuredisk-volume-tester-5jhlt"
    Jan 17 18:19:30.897: INFO: Pod azuredisk-volume-tester-5jhlt has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-5jhlt in namespace azuredisk-7089 01/17/23 18:19:30.897
    Jan 17 18:19:30.941: INFO: deleting PVC "azuredisk-7089"/"pvc-vkvrd"
    Jan 17 18:19:30.941: INFO: Deleting PersistentVolumeClaim "pvc-vkvrd"
... skipping 39 lines ...
STEP: checking the PVC 01/17/23 18:20:16.276
STEP: validating provisioned PV 01/17/23 18:20:16.312
STEP: checking the PV 01/17/23 18:20:16.347
STEP: setting up the pod 01/17/23 18:20:16.347
I0117 18:20:16.348091   15886 resource_setup.go:62] adding PV (pvc-6c718afe-3dfb-4a71-b754-1e9a7d21cb68) to pod ()
STEP: deploying the pod 01/17/23 18:20:16.348
STEP: checking that the pod's command exits with no error 01/17/23 18:20:16.386
Jan 17 18:20:16.386: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-glfml" in namespace "azuredisk-2466" to be "Succeeded or Failed"
Jan 17 18:20:16.441: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 54.844016ms
Jan 17 18:20:18.478: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 2.091549278s
Jan 17 18:20:20.481: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 4.094780311s
Jan 17 18:20:22.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 6.093771776s
Jan 17 18:20:24.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 8.093429457s
Jan 17 18:20:26.479: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 10.092502589s
... skipping 12 lines ...
Jan 17 18:20:52.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 36.090831891s
Jan 17 18:20:54.478: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=true. Elapsed: 38.091845342s
Jan 17 18:20:56.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=true. Elapsed: 40.09110933s
Jan 17 18:20:58.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=false. Elapsed: 42.09136107s
Jan 17 18:21:00.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.094220615s
STEP: Saw pod success 01/17/23 18:21:00.48
Jan 17 18:21:00.481: INFO: Pod "azuredisk-volume-tester-glfml" satisfied condition "Succeeded or Failed"
Jan 17 18:21:00.481: INFO: deleting Pod "azuredisk-2466"/"azuredisk-volume-tester-glfml"
Jan 17 18:21:00.521: INFO: Pod azuredisk-volume-tester-glfml has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-glfml in namespace azuredisk-2466 01/17/23 18:21:00.521
Jan 17 18:21:00.571: INFO: deleting PVC "azuredisk-2466"/"pvc-m2znv"
Jan 17 18:21:00.571: INFO: Deleting PersistentVolumeClaim "pvc-m2znv"
... skipping 40 lines ...
    STEP: checking the PVC 01/17/23 18:20:16.276
    STEP: validating provisioned PV 01/17/23 18:20:16.312
    STEP: checking the PV 01/17/23 18:20:16.347
    STEP: setting up the pod 01/17/23 18:20:16.347
    I0117 18:20:16.348091   15886 resource_setup.go:62] adding PV (pvc-6c718afe-3dfb-4a71-b754-1e9a7d21cb68) to pod ()
    STEP: deploying the pod 01/17/23 18:20:16.348
    STEP: checking that the pod's command exits with no error 01/17/23 18:20:16.386
    Jan 17 18:20:16.386: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-glfml" in namespace "azuredisk-2466" to be "Succeeded or Failed"
    Jan 17 18:20:16.441: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 54.844016ms
    Jan 17 18:20:18.478: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 2.091549278s
    Jan 17 18:20:20.481: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 4.094780311s
    Jan 17 18:20:22.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 6.093771776s
    Jan 17 18:20:24.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 8.093429457s
    Jan 17 18:20:26.479: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 10.092502589s
... skipping 12 lines ...
    Jan 17 18:20:52.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Pending", Reason="", readiness=false. Elapsed: 36.090831891s
    Jan 17 18:20:54.478: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=true. Elapsed: 38.091845342s
    Jan 17 18:20:56.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=true. Elapsed: 40.09110933s
    Jan 17 18:20:58.477: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Running", Reason="", readiness=false. Elapsed: 42.09136107s
    Jan 17 18:21:00.480: INFO: Pod "azuredisk-volume-tester-glfml": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.094220615s
    STEP: Saw pod success 01/17/23 18:21:00.48
    Jan 17 18:21:00.481: INFO: Pod "azuredisk-volume-tester-glfml" satisfied condition "Succeeded or Failed"
    Jan 17 18:21:00.481: INFO: deleting Pod "azuredisk-2466"/"azuredisk-volume-tester-glfml"
    Jan 17 18:21:00.521: INFO: Pod azuredisk-volume-tester-glfml has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-glfml in namespace azuredisk-2466 01/17/23 18:21:00.521
    Jan 17 18:21:00.571: INFO: deleting PVC "azuredisk-2466"/"pvc-m2znv"
    Jan 17 18:21:00.571: INFO: Deleting PersistentVolumeClaim "pvc-m2znv"
... skipping 111 lines ...
STEP: checking the PVC 01/17/23 18:21:47.298
STEP: validating provisioned PV 01/17/23 18:21:47.334
STEP: checking the PV 01/17/23 18:21:47.369
STEP: setting up the pod 01/17/23 18:21:47.369
I0117 18:21:47.369950   15886 resource_setup.go:62] adding PV (pvc-6916da9e-69c5-4af3-9545-a3bae9fe2fe0) to pod ()
STEP: deploying the pod 01/17/23 18:21:47.369
STEP: checking that the pod's command exits with an error 01/17/23 18:21:47.414
Jan 17 18:21:47.414: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-jclj5" in namespace "azuredisk-2390" to be "Error status code"
Jan 17 18:21:47.452: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 37.70905ms
Jan 17 18:21:49.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074593422s
Jan 17 18:21:51.491: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.076527544s
Jan 17 18:21:53.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.075112362s
Jan 17 18:21:55.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074158666s
Jan 17 18:21:57.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.075424358s
... skipping 8 lines ...
Jan 17 18:22:15.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 28.074061695s
Jan 17 18:22:17.490: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 30.075944791s
Jan 17 18:22:19.517: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 32.103232377s
Jan 17 18:22:21.490: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 34.075926079s
Jan 17 18:22:23.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 36.073982928s
Jan 17 18:22:25.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 38.075074402s
Jan 17 18:22:27.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Failed", Reason="", readiness=false. Elapsed: 40.074847417s
STEP: Saw pod failure 01/17/23 18:22:27.489
Jan 17 18:22:27.489: INFO: Pod "azuredisk-volume-tester-jclj5" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message 01/17/23 18:22:27.489
Jan 17 18:22:27.562: INFO: deleting Pod "azuredisk-2390"/"azuredisk-volume-tester-jclj5"
Jan 17 18:22:27.601: INFO: Pod azuredisk-volume-tester-jclj5 has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied.
At line:1 char:1
+ echo $null >> C:\mnt\test-1\data
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 49 lines ...
    STEP: checking the PVC 01/17/23 18:21:47.298
    STEP: validating provisioned PV 01/17/23 18:21:47.334
    STEP: checking the PV 01/17/23 18:21:47.369
    STEP: setting up the pod 01/17/23 18:21:47.369
    I0117 18:21:47.369950   15886 resource_setup.go:62] adding PV (pvc-6916da9e-69c5-4af3-9545-a3bae9fe2fe0) to pod ()
    STEP: deploying the pod 01/17/23 18:21:47.369
    STEP: checking that the pod's command exits with an error 01/17/23 18:21:47.414
    Jan 17 18:21:47.414: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-jclj5" in namespace "azuredisk-2390" to be "Error status code"
    Jan 17 18:21:47.452: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 37.70905ms
    Jan 17 18:21:49.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074593422s
    Jan 17 18:21:51.491: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.076527544s
    Jan 17 18:21:53.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.075112362s
    Jan 17 18:21:55.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074158666s
    Jan 17 18:21:57.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.075424358s
... skipping 8 lines ...
    Jan 17 18:22:15.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 28.074061695s
    Jan 17 18:22:17.490: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 30.075944791s
    Jan 17 18:22:19.517: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Pending", Reason="", readiness=false. Elapsed: 32.103232377s
    Jan 17 18:22:21.490: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 34.075926079s
    Jan 17 18:22:23.488: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 36.073982928s
    Jan 17 18:22:25.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Running", Reason="", readiness=true. Elapsed: 38.075074402s
    Jan 17 18:22:27.489: INFO: Pod "azuredisk-volume-tester-jclj5": Phase="Failed", Reason="", readiness=false. Elapsed: 40.074847417s
    STEP: Saw pod failure 01/17/23 18:22:27.489
    Jan 17 18:22:27.489: INFO: Pod "azuredisk-volume-tester-jclj5" satisfied condition "Error status code"
    STEP: checking that pod logs contain expected message 01/17/23 18:22:27.489
    Jan 17 18:22:27.562: INFO: deleting Pod "azuredisk-2390"/"azuredisk-volume-tester-jclj5"
    Jan 17 18:22:27.601: INFO: Pod azuredisk-volume-tester-jclj5 has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied.
    At line:1 char:1
    + echo $null >> C:\mnt\test-1\data
    + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
... skipping 168 lines ...