This job view page is being replaced by Spyglass soon. Check out the new job view.
PRandyzhangx: fix: panic when allow-empty-cloud-config is set
ResultABORTED
Tests 0 failed / 0 succeeded
Started2023-01-29 07:21
Elapsed38m38s
Revision28e9cda353861985bb045512a1eb4ebca3edf9b4
Refs 1699

No Test Failures!

Error lines from build-log.txt

... skipping 107 lines ...

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100 11345  100 11345    0     0   165k      0 --:--:-- --:--:-- --:--:--  165k
Downloading https://get.helm.sh/helm-v3.11.0-linux-amd64.tar.gz
Verifying checksum... Done.
Preparing to install helm into /usr/local/bin
helm installed into /usr/local/bin/helm
docker pull k8sprow.azurecr.io/azuredisk-csi:v1.27.0-91a71d20aca0952016e3206d14299d5c26740deb || make container-all push-manifest
Error response from daemon: manifest for k8sprow.azurecr.io/azuredisk-csi:v1.27.0-91a71d20aca0952016e3206d14299d5c26740deb not found: manifest unknown: manifest tagged by "v1.27.0-91a71d20aca0952016e3206d14299d5c26740deb" 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.27.0-91a71d20aca0952016e3206d14299d5c26740deb -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=91a71d20aca0952016e3206d14299d5c26740deb -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2023-01-29T07:28:08Z -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 1775 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 673 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.6.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 222 lines ...
Jan 29 07:38:42.417: INFO: PersistentVolumeClaim pvc-hlcl7 found and phase=Bound (4.085279235s)
STEP: checking the PVC 01/29/23 07:38:42.417
STEP: validating provisioned PV 01/29/23 07:38:42.443
STEP: checking the PV 01/29/23 07:38:42.469
STEP: setting up the pod 01/29/23 07:38:42.47
STEP: deploying the pod 01/29/23 07:38:42.47
STEP: checking that the pod's command exits with no error 01/29/23 07:38:42.5
Jan 29 07:38:42.500: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-6pjh4" in namespace "azuredisk-8081" to be "Succeeded or Failed"
Jan 29 07:38:42.527: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 27.32404ms
Jan 29 07:38:44.555: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05487324s
Jan 29 07:38:46.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05594054s
Jan 29 07:38:48.559: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059156531s
Jan 29 07:38:50.557: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.05728158s
Jan 29 07:38:52.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056298089s
... skipping 19 lines ...
Jan 29 07:39:32.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=true. Elapsed: 50.05617797s
Jan 29 07:39:34.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=true. Elapsed: 52.056076436s
Jan 29 07:39:36.554: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=false. Elapsed: 54.054589942s
Jan 29 07:39:38.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=false. Elapsed: 56.056761423s
Jan 29 07:39:40.553: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 58.053750032s
STEP: Saw pod success 01/29/23 07:39:40.554
Jan 29 07:39:40.554: INFO: Pod "azuredisk-volume-tester-6pjh4" satisfied condition "Succeeded or Failed"
Jan 29 07:39:40.554: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-6pjh4"
Jan 29 07:39:40.614: INFO: Pod azuredisk-volume-tester-6pjh4 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-6pjh4 in namespace azuredisk-8081 01/29/23 07:39:40.614
Jan 29 07:39:40.658: INFO: deleting PVC "azuredisk-8081"/"pvc-hlcl7"
Jan 29 07:39:40.658: INFO: Deleting PersistentVolumeClaim "pvc-hlcl7"
... skipping 63 lines ...
    Jan 29 07:38:42.417: INFO: PersistentVolumeClaim pvc-hlcl7 found and phase=Bound (4.085279235s)
    STEP: checking the PVC 01/29/23 07:38:42.417
    STEP: validating provisioned PV 01/29/23 07:38:42.443
    STEP: checking the PV 01/29/23 07:38:42.469
    STEP: setting up the pod 01/29/23 07:38:42.47
    STEP: deploying the pod 01/29/23 07:38:42.47
    STEP: checking that the pod's command exits with no error 01/29/23 07:38:42.5
    Jan 29 07:38:42.500: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-6pjh4" in namespace "azuredisk-8081" to be "Succeeded or Failed"
    Jan 29 07:38:42.527: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 27.32404ms
    Jan 29 07:38:44.555: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05487324s
    Jan 29 07:38:46.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05594054s
    Jan 29 07:38:48.559: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059156531s
    Jan 29 07:38:50.557: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.05728158s
    Jan 29 07:38:52.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056298089s
... skipping 19 lines ...
    Jan 29 07:39:32.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=true. Elapsed: 50.05617797s
    Jan 29 07:39:34.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=true. Elapsed: 52.056076436s
    Jan 29 07:39:36.554: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=false. Elapsed: 54.054589942s
    Jan 29 07:39:38.556: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Running", Reason="", readiness=false. Elapsed: 56.056761423s
    Jan 29 07:39:40.553: INFO: Pod "azuredisk-volume-tester-6pjh4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 58.053750032s
    STEP: Saw pod success 01/29/23 07:39:40.554
    Jan 29 07:39:40.554: INFO: Pod "azuredisk-volume-tester-6pjh4" satisfied condition "Succeeded or Failed"
    Jan 29 07:39:40.554: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-6pjh4"
    Jan 29 07:39:40.614: INFO: Pod azuredisk-volume-tester-6pjh4 has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-6pjh4 in namespace azuredisk-8081 01/29/23 07:39:40.614
    Jan 29 07:39:40.658: INFO: deleting PVC "azuredisk-8081"/"pvc-hlcl7"
    Jan 29 07:39:40.658: INFO: Deleting PersistentVolumeClaim "pvc-hlcl7"
... skipping 37 lines ...
Jan 29 07:40:23.636: INFO: PersistentVolumeClaim pvc-rhnr6 found but phase is Pending instead of Bound.
Jan 29 07:40:25.662: INFO: PersistentVolumeClaim pvc-rhnr6 found and phase=Bound (4.078589708s)
STEP: checking the PVC 01/29/23 07:40:25.662
STEP: validating provisioned PV 01/29/23 07:40:25.688
STEP: checking the PV 01/29/23 07:40:25.715
STEP: deploying the pod 01/29/23 07:40:25.715
STEP: checking that the pods command exits with no error 01/29/23 07:40:25.753
Jan 29 07:40:25.753: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-84sj6" in namespace "azuredisk-2540" to be "Succeeded or Failed"
Jan 29 07:40:25.783: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 29.78628ms
Jan 29 07:40:27.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057759187s
Jan 29 07:40:29.812: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059333229s
Jan 29 07:40:31.812: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059525103s
Jan 29 07:40:33.813: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059939525s
Jan 29 07:40:35.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058356764s
... skipping 20 lines ...
Jan 29 07:41:17.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=true. Elapsed: 52.057340221s
Jan 29 07:41:19.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=true. Elapsed: 54.057419235s
Jan 29 07:41:21.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=false. Elapsed: 56.05699102s
Jan 29 07:41:23.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=false. Elapsed: 58.058636509s
Jan 29 07:41:25.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m0.058560551s
STEP: Saw pod success 01/29/23 07:41:25.811
Jan 29 07:41:25.811: INFO: Pod "azuredisk-volume-tester-84sj6" satisfied condition "Succeeded or Failed"
Jan 29 07:41:25.812: INFO: deleting Pod "azuredisk-2540"/"azuredisk-volume-tester-84sj6"
Jan 29 07:41:25.872: INFO: Pod azuredisk-volume-tester-84sj6 has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-84sj6 in namespace azuredisk-2540 01/29/23 07:41:25.873
Jan 29 07:41:25.915: INFO: deleting PVC "azuredisk-2540"/"pvc-rhnr6"
Jan 29 07:41:25.915: INFO: Deleting PersistentVolumeClaim "pvc-rhnr6"
... skipping 38 lines ...
    Jan 29 07:40:23.636: INFO: PersistentVolumeClaim pvc-rhnr6 found but phase is Pending instead of Bound.
    Jan 29 07:40:25.662: INFO: PersistentVolumeClaim pvc-rhnr6 found and phase=Bound (4.078589708s)
    STEP: checking the PVC 01/29/23 07:40:25.662
    STEP: validating provisioned PV 01/29/23 07:40:25.688
    STEP: checking the PV 01/29/23 07:40:25.715
    STEP: deploying the pod 01/29/23 07:40:25.715
    STEP: checking that the pods command exits with no error 01/29/23 07:40:25.753
    Jan 29 07:40:25.753: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-84sj6" in namespace "azuredisk-2540" to be "Succeeded or Failed"
    Jan 29 07:40:25.783: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 29.78628ms
    Jan 29 07:40:27.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057759187s
    Jan 29 07:40:29.812: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059333229s
    Jan 29 07:40:31.812: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059525103s
    Jan 29 07:40:33.813: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059939525s
    Jan 29 07:40:35.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058356764s
... skipping 20 lines ...
    Jan 29 07:41:17.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=true. Elapsed: 52.057340221s
    Jan 29 07:41:19.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=true. Elapsed: 54.057419235s
    Jan 29 07:41:21.810: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=false. Elapsed: 56.05699102s
    Jan 29 07:41:23.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Running", Reason="", readiness=false. Elapsed: 58.058636509s
    Jan 29 07:41:25.811: INFO: Pod "azuredisk-volume-tester-84sj6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m0.058560551s
    STEP: Saw pod success 01/29/23 07:41:25.811
    Jan 29 07:41:25.811: INFO: Pod "azuredisk-volume-tester-84sj6" satisfied condition "Succeeded or Failed"
    Jan 29 07:41:25.812: INFO: deleting Pod "azuredisk-2540"/"azuredisk-volume-tester-84sj6"
    Jan 29 07:41:25.872: INFO: Pod azuredisk-volume-tester-84sj6 has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-84sj6 in namespace azuredisk-2540 01/29/23 07:41:25.873
    Jan 29 07:41:25.915: INFO: deleting PVC "azuredisk-2540"/"pvc-rhnr6"
    Jan 29 07:41:25.915: INFO: Deleting PersistentVolumeClaim "pvc-rhnr6"
... skipping 38 lines ...
Jan 29 07:42:10.925: INFO: PersistentVolumeClaim pvc-89n4r found and phase=Bound (4.101900821s)
STEP: checking the PVC 01/29/23 07:42:10.925
STEP: validating provisioned PV 01/29/23 07:42:10.951
STEP: checking the PV 01/29/23 07:42:10.977
STEP: setting up the pod 01/29/23 07:42:10.977
STEP: deploying the pod 01/29/23 07:42:10.977
STEP: checking that the pod's command exits with no error 01/29/23 07:42:11.007
Jan 29 07:42:11.007: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sm7cz" in namespace "azuredisk-4728" to be "Succeeded or Failed"
Jan 29 07:42:11.038: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 30.867823ms
Jan 29 07:42:13.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059226884s
Jan 29 07:42:15.065: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058335689s
Jan 29 07:42:17.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059749981s
Jan 29 07:42:19.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059385626s
Jan 29 07:42:21.071: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063848367s
... skipping 10 lines ...
Jan 29 07:42:43.069: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=true. Elapsed: 32.061664378s
Jan 29 07:42:45.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=true. Elapsed: 34.060131203s
Jan 29 07:42:47.068: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=false. Elapsed: 36.061283963s
Jan 29 07:42:49.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=false. Elapsed: 38.058574436s
Jan 29 07:42:51.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 40.060246688s
STEP: Saw pod success 01/29/23 07:42:51.067
Jan 29 07:42:51.067: INFO: Pod "azuredisk-volume-tester-sm7cz" satisfied condition "Succeeded or Failed"
Jan 29 07:42:51.067: INFO: deleting Pod "azuredisk-4728"/"azuredisk-volume-tester-sm7cz"
Jan 29 07:42:51.099: INFO: Pod azuredisk-volume-tester-sm7cz has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-sm7cz in namespace azuredisk-4728 01/29/23 07:42:51.099
Jan 29 07:42:51.147: INFO: deleting PVC "azuredisk-4728"/"pvc-89n4r"
Jan 29 07:42:51.147: INFO: Deleting PersistentVolumeClaim "pvc-89n4r"
... skipping 39 lines ...
    Jan 29 07:42:10.925: INFO: PersistentVolumeClaim pvc-89n4r found and phase=Bound (4.101900821s)
    STEP: checking the PVC 01/29/23 07:42:10.925
    STEP: validating provisioned PV 01/29/23 07:42:10.951
    STEP: checking the PV 01/29/23 07:42:10.977
    STEP: setting up the pod 01/29/23 07:42:10.977
    STEP: deploying the pod 01/29/23 07:42:10.977
    STEP: checking that the pod's command exits with no error 01/29/23 07:42:11.007
    Jan 29 07:42:11.007: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sm7cz" in namespace "azuredisk-4728" to be "Succeeded or Failed"
    Jan 29 07:42:11.038: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 30.867823ms
    Jan 29 07:42:13.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059226884s
    Jan 29 07:42:15.065: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058335689s
    Jan 29 07:42:17.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059749981s
    Jan 29 07:42:19.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059385626s
    Jan 29 07:42:21.071: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063848367s
... skipping 10 lines ...
    Jan 29 07:42:43.069: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=true. Elapsed: 32.061664378s
    Jan 29 07:42:45.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=true. Elapsed: 34.060131203s
    Jan 29 07:42:47.068: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=false. Elapsed: 36.061283963s
    Jan 29 07:42:49.066: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Running", Reason="", readiness=false. Elapsed: 38.058574436s
    Jan 29 07:42:51.067: INFO: Pod "azuredisk-volume-tester-sm7cz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 40.060246688s
    STEP: Saw pod success 01/29/23 07:42:51.067
    Jan 29 07:42:51.067: INFO: Pod "azuredisk-volume-tester-sm7cz" satisfied condition "Succeeded or Failed"
    Jan 29 07:42:51.067: INFO: deleting Pod "azuredisk-4728"/"azuredisk-volume-tester-sm7cz"
    Jan 29 07:42:51.099: INFO: Pod azuredisk-volume-tester-sm7cz has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-sm7cz in namespace azuredisk-4728 01/29/23 07:42:51.099
    Jan 29 07:42:51.147: INFO: deleting PVC "azuredisk-4728"/"pvc-89n4r"
    Jan 29 07:42:51.147: INFO: Deleting PersistentVolumeClaim "pvc-89n4r"
... skipping 182 lines ...
Jan 29 07:43:38.202: INFO: PersistentVolumeClaim pvc-997sk found and phase=Bound (4.079741563s)
STEP: checking the PVC 01/29/23 07:43:38.202
STEP: validating provisioned PV 01/29/23 07:43:38.228
STEP: checking the PV 01/29/23 07:43:38.257
STEP: setting up the pod 01/29/23 07:43:38.257
STEP: deploying the pod 01/29/23 07:43:38.257
STEP: checking that the pod's command exits with an error 01/29/23 07:43:38.291
Jan 29 07:43:38.292: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dqlqz" in namespace "azuredisk-1353" to be "Error status code"
Jan 29 07:43:38.325: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 32.946969ms
Jan 29 07:43:40.352: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060054645s
Jan 29 07:43:42.355: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.063108459s
Jan 29 07:43:44.353: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.061453629s
Jan 29 07:43:46.353: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061240421s
Jan 29 07:43:48.353: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.061303817s
... skipping 8 lines ...
Jan 29 07:44:06.352: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Pending", Reason="", readiness=false. Elapsed: 28.059973942s
Jan 29 07:44:08.353: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Running", Reason="", readiness=true. Elapsed: 30.061132632s
Jan 29 07:44:10.352: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Running", Reason="", readiness=true. Elapsed: 32.060143443s
Jan 29 07:44:12.352: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Running", Reason="", readiness=true. Elapsed: 34.060324899s
Jan 29 07:44:14.353: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Running", Reason="", readiness=false. Elapsed: 36.061109432s
Jan 29 07:44:16.352: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Running", Reason="", readiness=false. Elapsed: 38.05991167s
Jan 29 07:44:18.354: INFO: Pod "azuredisk-volume-tester-dqlqz": Phase="Failed", Reason="", readiness=false. Elapsed: 40.062211416s
STEP: Saw pod failure 01/29/23 07:44:18.354
Jan 29 07:44:18.354: INFO: Pod "azuredisk-volume-tester-dqlqz" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message 01/29/23 07:44:18.354
Jan 29 07:44:18.416: INFO: deleting Pod "azuredisk-1353"/"azuredisk-volume-tester-dqlqz"
Jan 29 07:44:18.446: INFO: Pod azuredisk-volume-tester-dqlqz 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 13 lines ...
Jan 29 07:44:28.606: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (10.082399459s)
Jan 29 07:44:33.642: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (15.118214286s)
Jan 29 07:44:38.674: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (20.150136372s)
Jan 29 07:44:43.701: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (25.177197793s)
Jan 29 07:44:48.742: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (30.217997568s)
Jan 29 07:44:53.772: INFO: PersistentVolume pvc-dd34cf2c-2422-4eab-b9b6-18b1f8dc804c found and phase=Released (35.248173479s)
{"component":"entrypoint","file":"k8s.io/test-infra/prow/entrypoint/run.go:168","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Entrypoint received interrupt: terminated","severity":"error","time":"2023-01-29T07:44:57Z"}
++ early_exit_handler
++ '[' -n 170 ']'
++ kill -TERM 170
++ cleanup_dind
++ [[ true == \t\r\u\e ]]
++ echo 'Cleaning up after docker'
... skipping 4 lines ...