This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: feat: support perf profile device setting on Linux node
ResultABORTED
Tests 0 failed / 24 succeeded
Started2022-11-14 11:44
Elapsed1h45m
Revision47d27f28476cc52fe2a235c6e940330b2dc7c991
Refs 1596

No Test Failures!


Show 24 Passed Tests

Show 38 Skipped Tests

Error lines from build-log.txt

... skipping 756 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 190 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11156  100 11156    0     0  74373      0 --:--:-- --:--:-- --:--:-- 74373
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-3ab911a8e7b9d8701c3411fadfeb2509a0485a8d || make container-all push-manifest
Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:v1.25.0-3ab911a8e7b9d8701c3411fadfeb2509a0485a8d not found: manifest unknown: manifest tagged by "v1.25.0-3ab911a8e7b9d8701c3411fadfeb2509a0485a8d" 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-3ab911a8e7b9d8701c3411fadfeb2509a0485a8d -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=3ab911a8e7b9d8701c3411fadfeb2509a0485a8d -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-11-14T12:09:23Z -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 1784 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 14 12:22:26.334: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-v6rfh] to have phase Bound
Nov 14 12:22:26.437: INFO: PersistentVolumeClaim pvc-v6rfh found and phase=Bound (102.459269ms)
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 14 12:22:26.752: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-bgkfs" in namespace "azuredisk-8081" to be "Error status code"
Nov 14 12:22:26.854: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 102.136931ms
Nov 14 12:22:28.958: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206063186s
Nov 14 12:22:31.067: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 4.315594025s
Nov 14 12:22:33.171: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 6.419224354s
Nov 14 12:22:35.274: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 8.522609973s
Nov 14 12:22:37.378: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Pending", Reason="", readiness=false. Elapsed: 10.625801554s
... skipping 195 lines ...
Nov 14 12:29:30.975: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=true. Elapsed: 7m4.223611147s
Nov 14 12:29:33.086: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=true. Elapsed: 7m6.333759367s
Nov 14 12:29:35.197: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=true. Elapsed: 7m8.445620592s
Nov 14 12:29:37.310: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=true. Elapsed: 7m10.558126065s
Nov 14 12:29:39.420: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=false. Elapsed: 7m12.668071934s
Nov 14 12:29:41.531: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Running", Reason="", readiness=false. Elapsed: 7m14.779479974s
Nov 14 12:29:43.644: INFO: Pod "azuredisk-volume-tester-bgkfs": Phase="Failed", Reason="", readiness=false. Elapsed: 7m16.891761796s
STEP: Saw pod failure
Nov 14 12:29:43.644: INFO: Pod "azuredisk-volume-tester-bgkfs" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Nov 14 12:29:43.773: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-bgkfs"
Nov 14 12:29:43.879: INFO: Pod azuredisk-volume-tester-bgkfs 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 101 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 14 12:30:21.237: 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 68 lines ...
Nov 14 12:30:34.204: INFO: PersistentVolumeClaim pvc-fzv6g found and phase=Bound (103.301901ms)
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 14 12:30:45.099: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fqp5d" in namespace "azuredisk-5194" to be "Succeeded or Failed"
Nov 14 12:30:45.228: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 129.557391ms
Nov 14 12:30:47.332: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.232878842s
Nov 14 12:30:49.437: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.337793422s
Nov 14 12:30:51.541: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.442311767s
Nov 14 12:30:53.646: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.547407027s
Nov 14 12:30:55.750: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Pending", Reason="", readiness=false. Elapsed: 10.651462645s
... skipping 28 lines ...
Nov 14 12:31:56.825: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Running", Reason="", readiness=true. Elapsed: 1m11.726641991s
Nov 14 12:31:58.934: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Running", Reason="", readiness=true. Elapsed: 1m13.835441285s
Nov 14 12:32:01.048: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Running", Reason="", readiness=false. Elapsed: 1m15.94915098s
Nov 14 12:32:03.158: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Running", Reason="", readiness=false. Elapsed: 1m18.058799745s
Nov 14 12:32:05.266: INFO: Pod "azuredisk-volume-tester-fqp5d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m20.167246792s
STEP: Saw pod success
Nov 14 12:32:05.266: INFO: Pod "azuredisk-volume-tester-fqp5d" satisfied condition "Succeeded or Failed"
Nov 14 12:32:05.266: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-fqp5d"
Nov 14 12:32:05.388: INFO: Pod azuredisk-volume-tester-fqp5d has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-fqp5d in namespace azuredisk-5194
Nov 14 12:32:05.828: INFO: deleting PVC "azuredisk-5194"/"pvc-fzv6g"
Nov 14 12:32:05.828: INFO: Deleting PersistentVolumeClaim "pvc-fzv6g"
... skipping 66 lines ...
Nov 14 12:32:31.400: INFO: PersistentVolumeClaim pvc-6p86w found and phase=Bound (4.318198381s)
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 14 12:32:31.715: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-h969p" in namespace "azuredisk-2888" to be "Succeeded or Failed"
Nov 14 12:32:31.818: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 102.657469ms
Nov 14 12:32:33.923: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.2072985s
Nov 14 12:32:36.028: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.312092547s
Nov 14 12:32:38.133: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 6.417375943s
Nov 14 12:32:40.242: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 8.526160852s
Nov 14 12:32:42.346: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Pending", Reason="", readiness=false. Elapsed: 10.630102932s
... skipping 17 lines ...
Nov 14 12:33:20.272: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Running", Reason="", readiness=true. Elapsed: 48.556786988s
Nov 14 12:33:22.383: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Running", Reason="", readiness=true. Elapsed: 50.667582657s
Nov 14 12:33:24.494: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Running", Reason="", readiness=false. Elapsed: 52.778461042s
Nov 14 12:33:26.603: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Running", Reason="", readiness=false. Elapsed: 54.887577686s
Nov 14 12:33:28.712: INFO: Pod "azuredisk-volume-tester-h969p": Phase="Succeeded", Reason="", readiness=false. Elapsed: 56.996112755s
STEP: Saw pod success
Nov 14 12:33:28.712: INFO: Pod "azuredisk-volume-tester-h969p" satisfied condition "Succeeded or Failed"
Nov 14 12:33:28.712: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-h969p"
Nov 14 12:33:28.824: INFO: Pod azuredisk-volume-tester-h969p has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-h969p in namespace azuredisk-2888
Nov 14 12:33:29.025: INFO: deleting PVC "azuredisk-2888"/"pvc-6p86w"
Nov 14 12:33:29.025: INFO: Deleting PersistentVolumeClaim "pvc-6p86w"
... skipping 45 lines ...
Nov 14 12:34:14.537: INFO: PersistentVolumeClaim pvc-l9x9z found but phase is Pending instead of Bound.
Nov 14 12:34:16.641: INFO: PersistentVolumeClaim pvc-l9x9z found and phase=Bound (4.308311128s)
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 14 12:34:16.953: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kzf5g" in namespace "azuredisk-156" to be "Succeeded or Failed"
Nov 14 12:34:17.075: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 121.735592ms
Nov 14 12:34:19.179: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 2.225630721s
Nov 14 12:34:21.282: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 4.329446092s
Nov 14 12:34:23.387: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 6.43389388s
Nov 14 12:34:25.492: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 8.538787127s
Nov 14 12:34:27.594: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Pending", Reason="", readiness=false. Elapsed: 10.641055942s
... skipping 20 lines ...
Nov 14 12:35:11.807: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Running", Reason="", readiness=true. Elapsed: 54.854201816s
Nov 14 12:35:13.916: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Running", Reason="", readiness=false. Elapsed: 56.962874094s
Nov 14 12:35:16.025: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Running", Reason="", readiness=false. Elapsed: 59.072216699s
Nov 14 12:35:18.134: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Running", Reason="", readiness=false. Elapsed: 1m1.180991877s
Nov 14 12:35:20.243: INFO: Pod "azuredisk-volume-tester-kzf5g": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m3.29039438s
STEP: Saw pod success
Nov 14 12:35:20.243: INFO: Pod "azuredisk-volume-tester-kzf5g" satisfied condition "Succeeded or Failed"
Nov 14 12:35:20.243: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-kzf5g"
Nov 14 12:35:20.369: INFO: Pod azuredisk-volume-tester-kzf5g has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-kzf5g in namespace azuredisk-156
Nov 14 12:35:20.492: INFO: deleting PVC "azuredisk-156"/"pvc-l9x9z"
Nov 14 12:35:20.492: INFO: Deleting PersistentVolumeClaim "pvc-l9x9z"
... skipping 46 lines ...
Nov 14 12:36:07.927: INFO: PersistentVolumeClaim pvc-v94lv found and phase=Bound (4.308972008s)
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 14 12:36:08.245: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-95pt9" in namespace "azuredisk-1563" to be "Succeeded or Failed"
Nov 14 12:36:08.347: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 101.778667ms
Nov 14 12:36:10.451: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205775283s
Nov 14 12:36:12.554: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.308672402s
Nov 14 12:36:14.658: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.412341774s
Nov 14 12:36:16.760: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.514656961s
Nov 14 12:36:18.863: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.617598141s
... skipping 17 lines ...
Nov 14 12:36:56.747: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Running", Reason="", readiness=true. Elapsed: 48.501744358s
Nov 14 12:36:58.857: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Running", Reason="", readiness=true. Elapsed: 50.611619612s
Nov 14 12:37:00.968: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Running", Reason="", readiness=false. Elapsed: 52.722340505s
Nov 14 12:37:03.077: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Running", Reason="", readiness=false. Elapsed: 54.832060052s
Nov 14 12:37:05.185: INFO: Pod "azuredisk-volume-tester-95pt9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 56.940113228s
STEP: Saw pod success
Nov 14 12:37:05.186: INFO: Pod "azuredisk-volume-tester-95pt9" satisfied condition "Succeeded or Failed"
Nov 14 12:37:05.186: INFO: deleting Pod "azuredisk-1563"/"azuredisk-volume-tester-95pt9"
Nov 14 12:37:05.306: INFO: Pod azuredisk-volume-tester-95pt9 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-95pt9 in namespace azuredisk-1563
Nov 14 12:37:05.430: INFO: deleting PVC "azuredisk-1563"/"pvc-v94lv"
Nov 14 12:37:05.430: INFO: Deleting PersistentVolumeClaim "pvc-v94lv"
... skipping 102 lines ...
Nov 14 12:37:56.071: INFO: PersistentVolumeClaim pvc-ffnq4 found and phase=Bound (4.30679998s)
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 14 12:37:56.386: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-t76m9" in namespace "azuredisk-9336" to be "Error status code"
Nov 14 12:37:56.489: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 103.371521ms
Nov 14 12:37:58.592: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.205973565s
Nov 14 12:38:00.696: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.309699583s
Nov 14 12:38:02.798: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.41210155s
Nov 14 12:38:04.901: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.514863374s
Nov 14 12:38:07.005: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.618745682s
... skipping 16 lines ...
Nov 14 12:38:42.788: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=true. Elapsed: 46.401698722s
Nov 14 12:38:44.897: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=true. Elapsed: 48.511412824s
Nov 14 12:38:47.007: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=true. Elapsed: 50.62098855s
Nov 14 12:38:49.115: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=false. Elapsed: 52.729268709s
Nov 14 12:38:51.225: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=false. Elapsed: 54.839251919s
Nov 14 12:38:53.334: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Running", Reason="", readiness=false. Elapsed: 56.948376296s
Nov 14 12:38:55.442: INFO: Pod "azuredisk-volume-tester-t76m9": Phase="Failed", Reason="", readiness=false. Elapsed: 59.056493617s
STEP: Saw pod failure
Nov 14 12:38:55.442: INFO: Pod "azuredisk-volume-tester-t76m9" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Nov 14 12:38:55.566: INFO: deleting Pod "azuredisk-9336"/"azuredisk-volume-tester-t76m9"
Nov 14 12:38:55.673: INFO: Pod azuredisk-volume-tester-t76m9 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 217 lines ...
Nov 14 12:45:55.181: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), LastTransitionTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), LastTransitionTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-f5dbd-5598b56846\" is progressing."}}, CollisionCount:(*int32)(nil)}
Nov 14 12:45:57.183: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), LastTransitionTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), LastTransitionTime:time.Date(2022, time.November, 14, 12, 45, 12, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-f5dbd-5598b56846\" is progressing."}}, CollisionCount:(*int32)(nil)}
STEP: checking that the pod is running
STEP: check pod exec
Nov 14 12:45:59.608: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azuredisk-8010 exec azuredisk-volume-tester-f5dbd-5598b56846-wqdqt -- cmd /c type C:\mnt\test-1\data.txt'
Nov 14 12:46:00.806: INFO: rc: 1
Nov 14 12:46:00.806: INFO: Error waiting for output "hello world\r\n" in pod "azuredisk-volume-tester-f5dbd-5598b56846-wqdqt": error running /usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azuredisk-8010 exec azuredisk-volume-tester-f5dbd-5598b56846-wqdqt -- cmd /c type C:\mnt\test-1\data.txt:
Command stdout:

stderr:
The system cannot find the file specified.
command terminated with exit code 1

error:
exit status 1.
Nov 14 12:46:02.808: INFO: Running '/usr/local/bin/kubectl --kubeconfig=/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/kubeconfig --namespace=azuredisk-8010 exec azuredisk-volume-tester-f5dbd-5598b56846-wqdqt -- cmd /c type C:\mnt\test-1\data.txt'
Nov 14 12:46:03.969: INFO: stderr: ""
Nov 14 12:46:03.969: INFO: stdout: "hello world\r\n"
STEP: deleting the pod for deployment
Nov 14 12:46:03.969: INFO: Deleting pod "azuredisk-volume-tester-f5dbd-5598b56846-wqdqt" in namespace "azuredisk-8010"
... skipping 238 lines ...
Nov 14 12:47:47.596: INFO: PersistentVolumeClaim pvc-9whwq found and phase=Bound (4.310664561s)
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 14 12:47:47.912: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-bpztk" in namespace "azuredisk-4547" to be "Succeeded or Failed"
Nov 14 12:47:48.022: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 109.245159ms
Nov 14 12:47:50.132: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.219864031s
Nov 14 12:47:52.242: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.330006711s
Nov 14 12:47:54.354: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.441389969s
Nov 14 12:47:56.464: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.551867751s
Nov 14 12:47:58.574: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.661963147s
... skipping 25 lines ...
Nov 14 12:48:53.447: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Running", Reason="", readiness=true. Elapsed: 1m5.53505081s
Nov 14 12:48:55.558: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Running", Reason="", readiness=false. Elapsed: 1m7.645843759s
Nov 14 12:48:57.668: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Running", Reason="", readiness=false. Elapsed: 1m9.755349894s
Nov 14 12:48:59.778: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Running", Reason="", readiness=false. Elapsed: 1m11.865296954s
Nov 14 12:49:01.888: INFO: Pod "azuredisk-volume-tester-bpztk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m13.975654476s
STEP: Saw pod success
Nov 14 12:49:01.888: INFO: Pod "azuredisk-volume-tester-bpztk" satisfied condition "Succeeded or Failed"
Nov 14 12:49:01.888: INFO: deleting Pod "azuredisk-4547"/"azuredisk-volume-tester-bpztk"
Nov 14 12:49:02.018: INFO: Pod azuredisk-volume-tester-bpztk has the following logs: hello world
hello world
hello world

STEP: Deleting pod azuredisk-volume-tester-bpztk in namespace azuredisk-4547
... skipping 101 lines ...
Nov 14 12:50:41.123: INFO: PersistentVolumeClaim pvc-7djlm found but phase is Pending instead of Bound.
Nov 14 12:50:43.226: INFO: PersistentVolumeClaim pvc-7djlm found and phase=Bound (4.310735522s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 14 12:50:43.543: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5hxrw" in namespace "azuredisk-9183" to be "Succeeded or Failed"
Nov 14 12:50:43.647: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 104.344766ms
Nov 14 12:50:45.752: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.209111383s
Nov 14 12:50:47.857: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.313592425s
Nov 14 12:50:49.961: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.417837099s
Nov 14 12:50:52.067: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.524021039s
Nov 14 12:50:54.172: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.6295298s
... skipping 16 lines ...
Nov 14 12:51:29.991: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Running", Reason="", readiness=true. Elapsed: 46.448132946s
Nov 14 12:51:32.100: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Running", Reason="", readiness=true. Elapsed: 48.557549541s
Nov 14 12:51:34.211: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Running", Reason="", readiness=false. Elapsed: 50.668398372s
Nov 14 12:51:36.322: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Running", Reason="", readiness=false. Elapsed: 52.778688485s
Nov 14 12:51:38.431: INFO: Pod "azuredisk-volume-tester-5hxrw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 54.88779546s
STEP: Saw pod success
Nov 14 12:51:38.431: INFO: Pod "azuredisk-volume-tester-5hxrw" satisfied condition "Succeeded or Failed"
STEP: Checking Prow test resource group
STEP: Prow test resource group: capz-am8u4k
STEP: Creating external resource group: azuredisk-csi-driver-test-1435d61f-641b-11ed-84f3-127eafb02820
STEP: creating volume snapshot class with external rg azuredisk-csi-driver-test-1435d61f-641b-11ed-84f3-127eafb02820
STEP: setting up the VolumeSnapshotClass
STEP: creating a VolumeSnapshotClass
... skipping 11 lines ...
Nov 14 12:52:00.547: INFO: PersistentVolumeClaim pvc-hqw86 found and phase=Bound (4.339130104s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: deploying a pod with a volume restored from the snapshot
STEP: checking that the pod's command exits with no error
Nov 14 12:52:00.877: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-k6dkq" in namespace "azuredisk-9183" to be "Succeeded or Failed"
Nov 14 12:52:00.989: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 111.652102ms
Nov 14 12:52:03.094: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.216522915s
Nov 14 12:52:05.198: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.321055064s
Nov 14 12:52:07.301: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.423973696s
Nov 14 12:52:09.405: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.528059869s
Nov 14 12:52:11.509: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.631798488s
... skipping 14 lines ...
Nov 14 12:52:43.095: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Running", Reason="", readiness=true. Elapsed: 42.217356653s
Nov 14 12:52:45.203: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Running", Reason="", readiness=true. Elapsed: 44.325476635s
Nov 14 12:52:47.313: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Running", Reason="", readiness=false. Elapsed: 46.435554332s
Nov 14 12:52:49.422: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Running", Reason="", readiness=false. Elapsed: 48.544534768s
Nov 14 12:52:51.554: INFO: Pod "azuredisk-volume-tester-k6dkq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.676514398s
STEP: Saw pod success
Nov 14 12:52:51.554: INFO: Pod "azuredisk-volume-tester-k6dkq" satisfied condition "Succeeded or Failed"
Nov 14 12:52:51.554: INFO: deleting Pod "azuredisk-9183"/"azuredisk-volume-tester-k6dkq"
Nov 14 12:52:51.692: INFO: Pod azuredisk-volume-tester-k6dkq has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-k6dkq in namespace azuredisk-9183
Nov 14 12:52:51.829: INFO: deleting PVC "azuredisk-9183"/"pvc-hqw86"
Nov 14 12:52:51.829: INFO: Deleting PersistentVolumeClaim "pvc-hqw86"
... skipping 61 lines ...
Nov 14 12:55:07.509: INFO: PersistentVolumeClaim pvc-zrw4k found but phase is Pending instead of Bound.
Nov 14 12:55:09.614: INFO: PersistentVolumeClaim pvc-zrw4k found and phase=Bound (4.310239702s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 14 12:55:09.932: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-mc2h4" in namespace "azuredisk-7578" to be "Succeeded or Failed"
Nov 14 12:55:10.034: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 102.136745ms
Nov 14 12:55:12.139: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.206594367s
Nov 14 12:55:14.243: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.310581316s
Nov 14 12:55:16.346: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.413941919s
Nov 14 12:55:18.453: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.520578844s
Nov 14 12:55:20.556: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.624384667s
... skipping 16 lines ...
Nov 14 12:55:56.543: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Running", Reason="", readiness=true. Elapsed: 46.610619794s
Nov 14 12:55:58.650: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Running", Reason="", readiness=true. Elapsed: 48.718462944s
Nov 14 12:56:00.760: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Running", Reason="", readiness=false. Elapsed: 50.827587511s
Nov 14 12:56:02.869: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Running", Reason="", readiness=false. Elapsed: 52.937166954s
Nov 14 12:56:04.978: INFO: Pod "azuredisk-volume-tester-mc2h4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 55.045853159s
STEP: Saw pod success
Nov 14 12:56:04.978: INFO: Pod "azuredisk-volume-tester-mc2h4" satisfied condition "Succeeded or Failed"
STEP: Checking Prow test resource group
STEP: Prow test resource group: capz-am8u4k
STEP: Creating external resource group: azuredisk-csi-driver-test-b315beb6-641b-11ed-84f3-127eafb02820
STEP: creating volume snapshot class with external rg azuredisk-csi-driver-test-b315beb6-641b-11ed-84f3-127eafb02820
STEP: setting up the VolumeSnapshotClass
STEP: creating a VolumeSnapshotClass
... skipping 14 lines ...
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: setting up the pod
STEP: Set pod anti-affinity to make sure two pods are scheduled on different nodes
STEP: deploying a pod with a volume restored from the snapshot
STEP: checking that the pod's command exits with no error
Nov 14 12:56:50.503: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dbvjz" in namespace "azuredisk-7578" to be "Succeeded or Failed"
Nov 14 12:56:50.609: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 105.897949ms
Nov 14 12:56:52.712: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.2091096s
Nov 14 12:56:54.815: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.311890776s
Nov 14 12:56:56.918: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.415232851s
Nov 14 12:56:59.021: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.518247447s
Nov 14 12:57:01.124: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.620907579s
... skipping 195 lines ...
Nov 14 13:03:54.562: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Running", Reason="", readiness=true. Elapsed: 7m4.058756625s
Nov 14 13:03:56.672: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Running", Reason="", readiness=true. Elapsed: 7m6.168477405s
Nov 14 13:03:58.782: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Running", Reason="", readiness=false. Elapsed: 7m8.279332636s
Nov 14 13:04:00.892: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Running", Reason="", readiness=false. Elapsed: 7m10.388545025s
Nov 14 13:04:03.003: INFO: Pod "azuredisk-volume-tester-dbvjz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 7m12.499525441s
STEP: Saw pod success
Nov 14 13:04:03.003: INFO: Pod "azuredisk-volume-tester-dbvjz" satisfied condition "Succeeded or Failed"
Nov 14 13:04:03.003: INFO: deleting Pod "azuredisk-7578"/"azuredisk-volume-tester-dbvjz"
Nov 14 13:04:03.125: INFO: Pod azuredisk-volume-tester-dbvjz has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-dbvjz in namespace azuredisk-7578
Nov 14 13:04:03.257: INFO: deleting PVC "azuredisk-7578"/"pvc-xpb2g"
Nov 14 13:04:03.257: INFO: Deleting PersistentVolumeClaim "pvc-xpb2g"
... skipping 88 lines ...
Nov 14 13:06:27.858: INFO: PersistentVolumeClaim pvc-78knj found but phase is Pending instead of Bound.
Nov 14 13:06:29.960: INFO: PersistentVolumeClaim pvc-78knj found and phase=Bound (4.307384698s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pod's command exits with no error
Nov 14 13:06:30.279: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-fd4s2" in namespace "azuredisk-1968" to be "Succeeded or Failed"
Nov 14 13:06:30.387: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 108.126467ms
Nov 14 13:06:32.497: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.217602707s
Nov 14 13:06:34.606: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.326177256s
Nov 14 13:06:36.715: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.435561182s
Nov 14 13:06:38.825: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.545596214s
Nov 14 13:06:40.934: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.654332157s
... skipping 22 lines ...
Nov 14 13:07:29.450: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Running", Reason="", readiness=true. Elapsed: 59.170857532s
Nov 14 13:07:31.558: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Running", Reason="", readiness=false. Elapsed: 1m1.279112015s
Nov 14 13:07:33.667: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Running", Reason="", readiness=false. Elapsed: 1m3.387293974s
Nov 14 13:07:35.776: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Running", Reason="", readiness=false. Elapsed: 1m5.496515626s
Nov 14 13:07:37.885: INFO: Pod "azuredisk-volume-tester-fd4s2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m7.605921419s
STEP: Saw pod success
Nov 14 13:07:37.885: INFO: Pod "azuredisk-volume-tester-fd4s2" satisfied condition "Succeeded or Failed"
Nov 14 13:07:37.885: INFO: deleting Pod "azuredisk-1968"/"azuredisk-volume-tester-fd4s2"
Nov 14 13:07:38.007: INFO: Pod azuredisk-volume-tester-fd4s2 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-fd4s2 in namespace azuredisk-1968
Nov 14 13:07:38.131: INFO: deleting PVC "azuredisk-1968"/"pvc-78knj"
Nov 14 13:07:38.131: INFO: Deleting PersistentVolumeClaim "pvc-78knj"
... skipping 353 lines ...