This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: test: set disk perf in PremiumV2 test
ResultABORTED
Tests 0 failed / 0 succeeded
Started2022-11-16 13:30
Elapsed1h16m
Revisiona4343d4bdbd7ddfad9687caf99a4f8b03a6cca80
Refs 1602

No Test Failures!

Error lines from build-log.txt

... skipping 759 lines ...
certificate.cert-manager.io "selfsigned-cert" deleted
# Create secret for AzureClusterIdentity
./hack/create-identity-secret.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Error from server (NotFound): secrets "cluster-identity-secret" not found
secret/cluster-identity-secret created
secret/cluster-identity-secret labeled
# Create customized cloud provider configs
./hack/create-custom-cloud-provider-config.sh
make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
make[2]: Nothing to be done for 'kubectl'.
... skipping 137 lines ...
# Wait for the kubeconfig to become available.
timeout --foreground 300 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets | grep capz-zkph22-kubeconfig; do sleep 1; done"
capz-zkph22-kubeconfig                 cluster.x-k8s.io/secret   1      1s
# Get kubeconfig and store it locally.
/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets capz-zkph22-kubeconfig -o json | jq -r .data.value | base64 --decode > ./kubeconfig
timeout --foreground 600 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig get nodes | grep control-plane; do sleep 1; done"
error: the server doesn't have a resource type "nodes"
capz-zkph22-control-plane-58nh8   NotReady   control-plane,master   6s    v1.23.15-rc.0.11+2b8076aad0e0b8
run "/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig ..." to work with the new target cluster
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure'
Waiting for 1 control plane machine(s), 0 worker machine(s), and 2 windows machine(s) to become Ready
node/capz-zkph-fxzgl condition met
node/capz-zkph-t2v8r condition met
... skipping 36 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0   184k      0 --:--:-- --:--:-- --:--:--  184k
Downloading https://get.helm.sh/helm-v3.10.2-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull capzci.azurecr.io/azuredisk-csi:v1.25.0-654ae300793ea3ef30c3b230e1d6f5c944c5118a || make container-all push-manifest
Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:v1.25.0-654ae300793ea3ef30c3b230e1d6f5c944c5118a not found: manifest unknown: manifest tagged by "v1.25.0-654ae300793ea3ef30c3b230e1d6f5c944c5118a" 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.25.0-654ae300793ea3ef30c3b230e1d6f5c944c5118a -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=654ae300793ea3ef30c3b230e1d6f5c944c5118a -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-11-16T13:47:38Z -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 1766 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 613 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 210 lines ...
Nov 16 14:01:49.337: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-q7bz4] to have phase Bound
Nov 16 14:01:49.445: INFO: PersistentVolumeClaim pvc-q7bz4 found and phase=Bound (107.9442ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Nov 16 14:01:49.772: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dcs2n" in namespace "azuredisk-8081" to be "Error status code"
Nov 16 14:01:49.880: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 108.048437ms
Nov 16 14:01:51.990: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 2.217550457s
Nov 16 14:01:54.098: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 4.326247568s
Nov 16 14:01:56.208: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435842377s
Nov 16 14:01:58.318: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545581415s
Nov 16 14:02:00.427: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Pending", Reason="", readiness=false. Elapsed: 10.655221194s
... skipping 274 lines ...
Nov 16 14:11:42.344: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=true. Elapsed: 9m52.571534267s
Nov 16 14:11:44.461: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=true. Elapsed: 9m54.688737406s
Nov 16 14:11:46.577: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=true. Elapsed: 9m56.804582312s
Nov 16 14:11:48.695: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=false. Elapsed: 9m58.922808472s
Nov 16 14:11:50.812: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=false. Elapsed: 10m1.039800786s
Nov 16 14:11:52.929: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Running", Reason="", readiness=false. Elapsed: 10m3.156560302s
Nov 16 14:11:55.046: INFO: Pod "azuredisk-volume-tester-dcs2n": Phase="Failed", Reason="", readiness=false. Elapsed: 10m5.273797219s
STEP: Saw pod failure
Nov 16 14:11:55.046: INFO: Pod "azuredisk-volume-tester-dcs2n" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Nov 16 14:11:55.193: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-dcs2n"
Nov 16 14:11:55.306: INFO: Pod azuredisk-volume-tester-dcs2n 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 102 lines ...
  [single-az]
  /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:69
    should succeed when creating a shared disk [disk.csi.azure.com][windows]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:143
------------------------------
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
Nov 16 14:12:38.782: INFO: >>> kubeConfig: /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig
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 137 lines ...
/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 succeed when creating a PremiumV2_LRS disk [disk.csi.azure.com][windows] [It]
    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:250

    create volume error: rpc error: code = Internal desc = Retriable: false, RetryAfter: 0s, HTTPStatusCode: 400, RawError: {

      "error": {

        "code": "BadRequest",
        "message": "The value 1000 of parameter disk.diskIOPSReadWrite is not valid. The supported range for a PremiumV2_LRS disk of size 100 GB is between 3000 and 50000."
      }
    }

    /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:265
... skipping 18 lines ...
Nov 16 14:12:53.612: INFO: PersistentVolumeClaim pvc-slngh found and phase=Bound (107.846535ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: attaching disk to node#0
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 16 14:13:09.527: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ffxzf" in namespace "azuredisk-5194" to be "Succeeded or Failed"
Nov 16 14:13:09.636: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 108.691166ms
Nov 16 14:13:11.745: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.218071679s
Nov 16 14:13:13.855: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.32773448s
Nov 16 14:13:15.965: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.437594753s
Nov 16 14:13:18.080: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.552508187s
Nov 16 14:13:20.189: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.661479012s
... skipping 256 lines ...
Nov 16 14:22:22.572: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Running", Reason="", readiness=true. Elapsed: 9m13.044269139s
Nov 16 14:22:24.683: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Running", Reason="", readiness=false. Elapsed: 9m15.155663054s
Nov 16 14:22:26.794: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Running", Reason="", readiness=false. Elapsed: 9m17.267039972s
Nov 16 14:22:28.906: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Running", Reason="", readiness=false. Elapsed: 9m19.378561198s
Nov 16 14:22:31.018: INFO: Pod "azuredisk-volume-tester-ffxzf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 9m21.490116636s
STEP: Saw pod success
Nov 16 14:22:31.018: INFO: Pod "azuredisk-volume-tester-ffxzf" satisfied condition "Succeeded or Failed"
Nov 16 14:22:31.018: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-ffxzf"
Nov 16 14:22:31.151: INFO: Pod azuredisk-volume-tester-ffxzf has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-ffxzf in namespace azuredisk-5194
Nov 16 14:22:31.596: INFO: deleting PVC "azuredisk-5194"/"pvc-slngh"
Nov 16 14:22:31.596: INFO: Deleting PersistentVolumeClaim "pvc-slngh"
... skipping 68 lines ...
Nov 16 14:23:07.637: INFO: PersistentVolumeClaim pvc-7b6p7 found and phase=Bound (4.327893191s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 16 14:23:07.966: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-j57d8" in namespace "azuredisk-2888" to be "Succeeded or Failed"
Nov 16 14:23:08.076: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 110.156192ms
Nov 16 14:23:10.186: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219663752s
Nov 16 14:23:12.295: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.329090392s
Nov 16 14:23:14.410: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.443548557s
Nov 16 14:23:16.521: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.55502009s
Nov 16 14:23:18.631: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.664504159s
... skipping 20 lines ...
Nov 16 14:24:02.955: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Running", Reason="", readiness=true. Elapsed: 54.9886336s
Nov 16 14:24:05.067: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Running", Reason="", readiness=false. Elapsed: 57.100638767s
Nov 16 14:24:07.178: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Running", Reason="", readiness=false. Elapsed: 59.211924742s
Nov 16 14:24:09.289: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Running", Reason="", readiness=false. Elapsed: 1m1.323196461s
Nov 16 14:24:11.401: INFO: Pod "azuredisk-volume-tester-j57d8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m3.43492511s
STEP: Saw pod success
Nov 16 14:24:11.401: INFO: Pod "azuredisk-volume-tester-j57d8" satisfied condition "Succeeded or Failed"
Nov 16 14:24:11.401: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-j57d8"
Nov 16 14:24:11.532: INFO: Pod azuredisk-volume-tester-j57d8 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-j57d8 in namespace azuredisk-2888
Nov 16 14:24:11.653: INFO: deleting PVC "azuredisk-2888"/"pvc-7b6p7"
Nov 16 14:24:11.653: INFO: Deleting PersistentVolumeClaim "pvc-7b6p7"
... skipping 51 lines ...
Nov 16 14:25:27.834: INFO: PersistentVolumeClaim pvc-nmngm found but phase is Pending instead of Bound.
Nov 16 14:25:29.944: INFO: PersistentVolumeClaim pvc-nmngm found and phase=Bound (4.329064415s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Nov 16 14:25:30.281: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-tnq9m" in namespace "azuredisk-156" to be "Succeeded or Failed"
Nov 16 14:25:30.390: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 109.041308ms
Nov 16 14:25:32.501: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.220590326s
Nov 16 14:25:34.610: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 4.329770839s
Nov 16 14:25:36.720: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 6.438892165s
Nov 16 14:25:38.829: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 8.548452035s
Nov 16 14:25:40.940: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Pending", Reason="", readiness=false. Elapsed: 10.659194301s
... skipping 23 lines ...
Nov 16 14:26:31.601: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Running", Reason="", readiness=true. Elapsed: 1m1.320351641s
Nov 16 14:26:33.712: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Running", Reason="", readiness=false. Elapsed: 1m3.431740408s
Nov 16 14:26:35.823: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Running", Reason="", readiness=false. Elapsed: 1m5.542675063s
Nov 16 14:26:37.935: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Running", Reason="", readiness=false. Elapsed: 1m7.654290357s
Nov 16 14:26:40.046: INFO: Pod "azuredisk-volume-tester-tnq9m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m9.765843615s
STEP: Saw pod success
Nov 16 14:26:40.047: INFO: Pod "azuredisk-volume-tester-tnq9m" satisfied condition "Succeeded or Failed"
Nov 16 14:26:40.047: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-tnq9m"
Nov 16 14:26:40.191: INFO: Pod azuredisk-volume-tester-tnq9m has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-tnq9m in namespace azuredisk-156
Nov 16 14:26:40.316: INFO: deleting PVC "azuredisk-156"/"pvc-nmngm"
Nov 16 14:26:40.316: INFO: Deleting PersistentVolumeClaim "pvc-nmngm"
... skipping 52 lines ...
Nov 16 14:27:58.597: INFO: PersistentVolumeClaim pvc-hgwqh found and phase=Bound (4.327745696s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 16 14:27:58.928: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-vnd45" in namespace "azuredisk-1563" to be "Succeeded or Failed"
Nov 16 14:27:59.037: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 108.761823ms
Nov 16 14:28:01.147: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219597594s
Nov 16 14:28:03.257: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 4.329508398s
Nov 16 14:28:05.368: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 6.439894773s
Nov 16 14:28:07.484: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 8.555621876s
Nov 16 14:28:09.594: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Pending", Reason="", readiness=false. Elapsed: 10.66641481s
... skipping 20 lines ...
Nov 16 14:28:53.913: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Running", Reason="", readiness=true. Elapsed: 54.98481185s
Nov 16 14:28:56.023: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Running", Reason="", readiness=true. Elapsed: 57.095216021s
Nov 16 14:28:58.135: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Running", Reason="", readiness=false. Elapsed: 59.206828838s
Nov 16 14:29:00.245: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Running", Reason="", readiness=false. Elapsed: 1m1.31743065s
Nov 16 14:29:02.357: INFO: Pod "azuredisk-volume-tester-vnd45": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m3.428903807s
STEP: Saw pod success
Nov 16 14:29:02.357: INFO: Pod "azuredisk-volume-tester-vnd45" satisfied condition "Succeeded or Failed"
Nov 16 14:29:02.357: INFO: deleting Pod "azuredisk-1563"/"azuredisk-volume-tester-vnd45"
Nov 16 14:29:02.488: INFO: Pod azuredisk-volume-tester-vnd45 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-vnd45 in namespace azuredisk-1563
Nov 16 14:29:02.609: INFO: deleting PVC "azuredisk-1563"/"pvc-hgwqh"
Nov 16 14:29:02.609: INFO: Deleting PersistentVolumeClaim "pvc-hgwqh"
... skipping 102 lines ...
Nov 16 14:29:53.648: INFO: PersistentVolumeClaim pvc-75dnr found and phase=Bound (4.328293232s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying the pod
STEP: checking that the pod's command exits with an error
Nov 16 14:29:53.983: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-l46qm" in namespace "azuredisk-9336" to be "Error status code"
Nov 16 14:29:54.092: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 109.248241ms
Nov 16 14:29:56.202: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.218946589s
Nov 16 14:29:58.312: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.329429464s
Nov 16 14:30:00.423: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.43999322s
Nov 16 14:30:02.532: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.548974436s
Nov 16 14:30:04.641: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.658447461s
... skipping 33 lines ...
Nov 16 14:31:16.386: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=true. Elapsed: 1m22.403829626s
Nov 16 14:31:18.498: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=true. Elapsed: 1m24.515345888s
Nov 16 14:31:20.609: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=true. Elapsed: 1m26.626833437s
Nov 16 14:31:22.721: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=true. Elapsed: 1m28.738103352s
Nov 16 14:31:24.832: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=false. Elapsed: 1m30.849060517s
Nov 16 14:31:26.943: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Running", Reason="", readiness=false. Elapsed: 1m32.960505392s
Nov 16 14:31:29.055: INFO: Pod "azuredisk-volume-tester-l46qm": Phase="Failed", Reason="", readiness=false. Elapsed: 1m35.071993209s
STEP: Saw pod failure
Nov 16 14:31:29.055: INFO: Pod "azuredisk-volume-tester-l46qm" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Nov 16 14:31:29.197: INFO: deleting Pod "azuredisk-9336"/"azuredisk-volume-tester-l46qm"
Nov 16 14:31:29.314: INFO: Pod azuredisk-volume-tester-l46qm 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 59 lines ...