This job view page is being replaced by Spyglass soon. Check out the new job view.
PRhccheng72: [V2] fix: update replica attachment failure retries logic
ResultABORTED
Tests 0 failed / 0 succeeded
Started2023-01-20 01:36
Elapsed29m37s
Revision53f78422b47482fea7c89027d91f9f28d4acfa16
Refs 1650

No Test Failures!


Error lines from build-log.txt

... skipping 966 lines ...
                    type: string
                type: object
                oneOf:
                - required: ["persistentVolumeClaimName"]
                - required: ["volumeSnapshotContentName"]
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 60 lines ...
                    type: string
                  volumeSnapshotContentName:
                    description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable.
                    type: string
                type: object
              volumeSnapshotClassName:
                description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.'
                type: string
            required:
            - source
            type: object
          status:
            description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.
... skipping 2 lines ...
                description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.'
                type: string
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown.
                format: date-time
                type: string
              error:
                description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurs during the snapshot creation. Upon success, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                type: string
                description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$
                x-kubernetes-int-or-string: true
            type: object
        required:
        - spec
        type: object
... skipping 254 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 108 lines ...
            description: status represents the current information of a snapshot.
            properties:
              creationTime:
                description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC.
                format: int64
                type: integer
              error:
                description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared.
                properties:
                  message:
                    description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.'
                    type: string
                  time:
                    description: time is the timestamp when the error was encountered.
                    format: date-time
                    type: string
                type: object
              readyToUse:
                description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown.
                type: boolean
              restoreSize:
                description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown.
                format: int64
                minimum: 0
                type: integer
              snapshotHandle:
                description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress.
                type: string
            type: object
        required:
        - spec
        type: object
    served: true
... skipping 359 lines ...
            - volumeName
            - volume_context
            - volume_id
            type: object
          status:
            description: status represents the current state of AzVolumeAttachment.
              includes error, state, and attachment status Required
            properties:
              detail:
                description: Status summarizes the current attachment state of the
                  volume attachment Nil Status indicates that the volume has not yet
                  been attached to the node
                properties:
... skipping 7 lines ...
                  role:
                    description: The current attachment role.
                    type: string
                required:
                - role
                type: object
              error:
                description: Error occurred during attach/detach of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 90 lines ...
            - volumeName
            - volume_context
            - volume_id
            type: object
          status:
            description: status represents the current state of AzVolumeAttachment.
              includes error, state, and attachment status
            properties:
              annotation:
                additionalProperties:
                  type: string
                description: Annotations contains additional resource information
                  to guide driver actions
... skipping 13 lines ...
                  role:
                    description: The current attachment role.
                    type: string
                required:
                - role
                type: object
              error:
                description: Error occurred during attach/detach of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 169 lines ...
            - maxMountReplicaCount
            - volumeCapability
            - volumeName
            type: object
          status:
            description: status represents the current state of AzVolume. includes
              error, state, and volume status
            properties:
              detail:
                description: Current status detail of the AzVolume Nil detail indicates
                  that the volume has not been created
                properties:
                  accessible_topology:
... skipping 28 lines ...
                    type: string
                required:
                - capacity_bytes
                - node_expansion_required
                - volume_id
                type: object
              error:
                description: Error occurred during creation/deletion of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 154 lines ...
            - maxMountReplicaCount
            - volumeCapability
            - volumeName
            type: object
          status:
            description: status represents the current state of AzVolume. includes
              error, state, and volume status
            properties:
              annotation:
                additionalProperties:
                  type: string
                description: Annotations contains additional resource information
                  to guide driver actions
... skipping 34 lines ...
                    type: string
                required:
                - capacity_bytes
                - node_expansion_required
                - volume_id
                type: object
              error:
                description: Error occurred during creation/deletion of volume
                properties:
                  code:
                    type: string
                  message:
                    type: string
                  parameters:
... skipping 883 lines ...
          image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.5.0"
          args:
            - "-csi-address=$(ADDRESS)"
            - "-v=2"
            - "-leader-election"
            - "--leader-election-namespace=kube-system"
            - '-handle-volume-inuse-error=false'
            - '-feature-gates=RecoverVolumeExpansionFailure=true'
            - "-timeout=240s"
          env:
            - name: ADDRESS
              value: /csi/csi.sock
          volumeMounts:
... skipping 296 lines ...
Jan 20 01:43:38.056: INFO: PersistentVolumeClaim pvc-llckj found but phase is Pending instead of Bound.
Jan 20 01:43:40.088: INFO: PersistentVolumeClaim pvc-llckj found and phase=Bound (2.07151186s)
STEP: checking the PVC 01/20/23 01:43:40.088
STEP: validating provisioned PV 01/20/23 01:43:40.116
STEP: checking the PV 01/20/23 01:43:40.145
STEP: deploying the pod 01/20/23 01:43:40.145
STEP: checking that the pod's command exits with an error 01/20/23 01:43:40.18
Jan 20 01:43:40.180: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-6nzhl" in namespace "azuredisk-9730" to be "Error status code"
Jan 20 01:43:40.231: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 50.634192ms
Jan 20 01:43:42.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081396966s
Jan 20 01:43:44.269: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.088865463s
Jan 20 01:43:46.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.082079179s
Jan 20 01:43:48.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.080745437s
Jan 20 01:43:50.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.081793731s
... skipping 31 lines ...
Jan 20 01:44:54.263: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=true. Elapsed: 1m14.083243353s
Jan 20 01:44:56.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m16.080710442s
Jan 20 01:44:58.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m18.080523315s
Jan 20 01:45:00.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m20.082126179s
Jan 20 01:45:02.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m22.081928815s
Jan 20 01:45:04.263: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m24.083035138s
Jan 20 01:45:06.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Failed", Reason="", readiness=false. Elapsed: 1m26.082300237s
STEP: Saw pod failure 01/20/23 01:45:06.262
Jan 20 01:45:06.263: INFO: Pod "azuredisk-volume-tester-6nzhl" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message 01/20/23 01:45:06.263
Jan 20 01:45:06.335: INFO: deleting Pod "azuredisk-9730"/"azuredisk-volume-tester-6nzhl"
Jan 20 01:45:06.369: INFO: Pod azuredisk-volume-tester-6nzhl 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 55 lines ...
    Jan 20 01:43:38.056: INFO: PersistentVolumeClaim pvc-llckj found but phase is Pending instead of Bound.
    Jan 20 01:43:40.088: INFO: PersistentVolumeClaim pvc-llckj found and phase=Bound (2.07151186s)
    STEP: checking the PVC 01/20/23 01:43:40.088
    STEP: validating provisioned PV 01/20/23 01:43:40.116
    STEP: checking the PV 01/20/23 01:43:40.145
    STEP: deploying the pod 01/20/23 01:43:40.145
    STEP: checking that the pod's command exits with an error 01/20/23 01:43:40.18
    Jan 20 01:43:40.180: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-6nzhl" in namespace "azuredisk-9730" to be "Error status code"
    Jan 20 01:43:40.231: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 50.634192ms
    Jan 20 01:43:42.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.081396966s
    Jan 20 01:43:44.269: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.088865463s
    Jan 20 01:43:46.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.082079179s
    Jan 20 01:43:48.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.080745437s
    Jan 20 01:43:50.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.081793731s
... skipping 31 lines ...
    Jan 20 01:44:54.263: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=true. Elapsed: 1m14.083243353s
    Jan 20 01:44:56.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m16.080710442s
    Jan 20 01:44:58.261: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m18.080523315s
    Jan 20 01:45:00.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m20.082126179s
    Jan 20 01:45:02.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m22.081928815s
    Jan 20 01:45:04.263: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Running", Reason="", readiness=false. Elapsed: 1m24.083035138s
    Jan 20 01:45:06.262: INFO: Pod "azuredisk-volume-tester-6nzhl": Phase="Failed", Reason="", readiness=false. Elapsed: 1m26.082300237s
    STEP: Saw pod failure 01/20/23 01:45:06.262
    Jan 20 01:45:06.263: INFO: Pod "azuredisk-volume-tester-6nzhl" satisfied condition "Error status code"
    STEP: checking that pod logs contain expected message 01/20/23 01:45:06.263
    Jan 20 01:45:06.335: INFO: deleting Pod "azuredisk-9730"/"azuredisk-volume-tester-6nzhl"
    Jan 20 01:45:06.369: INFO: Pod azuredisk-volume-tester-6nzhl 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 84 lines ...
Jan 20 01:45:43.639: INFO: PersistentVolumeClaim pvc-8s8ll found and phase=Bound (2.073259994s)
STEP: checking the PVC 01/20/23 01:45:43.639
STEP: validating provisioned PV 01/20/23 01:45:43.673
STEP: checking the PV 01/20/23 01:45:43.706
STEP: attaching disk to node#0 01/20/23 01:45:43.736
STEP: deploying the pod 01/20/23 01:45:55.987
STEP: checking that the pod's command exits with no error 01/20/23 01:45:56.02
Jan 20 01:45:56.021: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5kckn" in namespace "azuredisk-2600" to be "Succeeded or Failed"
Jan 20 01:45:56.049: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 28.425ms
Jan 20 01:45:58.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059836872s
Jan 20 01:46:00.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058099706s
Jan 20 01:46:02.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059174633s
Jan 20 01:46:04.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058374879s
Jan 20 01:46:06.078: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057673881s
... skipping 42 lines ...
Jan 20 01:47:32.088: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m36.067108032s
Jan 20 01:47:34.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m38.059320839s
Jan 20 01:47:36.078: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m40.057814292s
Jan 20 01:47:38.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m42.058247743s
Jan 20 01:47:40.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m44.05831576s
STEP: Saw pod success 01/20/23 01:47:40.079
Jan 20 01:47:40.079: INFO: Pod "azuredisk-volume-tester-5kckn" satisfied condition "Succeeded or Failed"
Jan 20 01:47:40.079: INFO: deleting Pod "azuredisk-2600"/"azuredisk-volume-tester-5kckn"
Jan 20 01:47:40.139: INFO: Pod azuredisk-volume-tester-5kckn has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-5kckn in namespace azuredisk-2600 01/20/23 01:47:40.139
Jan 20 01:47:40.272: INFO: deleting PVC "azuredisk-2600"/"pvc-8s8ll"
Jan 20 01:47:40.272: INFO: Deleting PersistentVolumeClaim "pvc-8s8ll"
... skipping 40 lines ...
    Jan 20 01:45:43.639: INFO: PersistentVolumeClaim pvc-8s8ll found and phase=Bound (2.073259994s)
    STEP: checking the PVC 01/20/23 01:45:43.639
    STEP: validating provisioned PV 01/20/23 01:45:43.673
    STEP: checking the PV 01/20/23 01:45:43.706
    STEP: attaching disk to node#0 01/20/23 01:45:43.736
    STEP: deploying the pod 01/20/23 01:45:55.987
    STEP: checking that the pod's command exits with no error 01/20/23 01:45:56.02
    Jan 20 01:45:56.021: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5kckn" in namespace "azuredisk-2600" to be "Succeeded or Failed"
    Jan 20 01:45:56.049: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 28.425ms
    Jan 20 01:45:58.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059836872s
    Jan 20 01:46:00.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058099706s
    Jan 20 01:46:02.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059174633s
    Jan 20 01:46:04.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058374879s
    Jan 20 01:46:06.078: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057673881s
... skipping 42 lines ...
    Jan 20 01:47:32.088: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m36.067108032s
    Jan 20 01:47:34.080: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m38.059320839s
    Jan 20 01:47:36.078: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m40.057814292s
    Jan 20 01:47:38.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Running", Reason="", readiness=false. Elapsed: 1m42.058247743s
    Jan 20 01:47:40.079: INFO: Pod "azuredisk-volume-tester-5kckn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m44.05831576s
    STEP: Saw pod success 01/20/23 01:47:40.079
    Jan 20 01:47:40.079: INFO: Pod "azuredisk-volume-tester-5kckn" satisfied condition "Succeeded or Failed"
    Jan 20 01:47:40.079: INFO: deleting Pod "azuredisk-2600"/"azuredisk-volume-tester-5kckn"
    Jan 20 01:47:40.139: INFO: Pod azuredisk-volume-tester-5kckn has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-5kckn in namespace azuredisk-2600 01/20/23 01:47:40.139
    Jan 20 01:47:40.272: INFO: deleting PVC "azuredisk-2600"/"pvc-8s8ll"
    Jan 20 01:47:40.272: INFO: Deleting PersistentVolumeClaim "pvc-8s8ll"
... skipping 152 lines ...
  << End Captured GinkgoWriter Output

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

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

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

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

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

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

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

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

        "code": "NotFound",
        "message": "Disk single-shared-disk is not found."
      }
    }
    In [AfterEach] at: /home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:490
------------------------------
... skipping 23 lines ...
STEP: checking the PVC 01/20/23 01:48:44.973
STEP: validating provisioned PV 01/20/23 01:48:45.002
STEP: checking the PV 01/20/23 01:48:45.03
STEP: setting up the pod 01/20/23 01:48:45.03
I0120 01:48:45.030959   16025 resource_setup.go:62] adding PV (pvc-f319c7a5-6e02-4afe-bfd8-503120da2c75) to pod ()
STEP: deploying the pod 01/20/23 01:48:45.03
STEP: checking that the pod's command exits with no error 01/20/23 01:48:45.07
Jan 20 01:48:45.071: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ps6vr" in namespace "azuredisk-5168" to be "Succeeded or Failed"
Jan 20 01:48:45.103: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 32.581237ms
Jan 20 01:48:47.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063809408s
Jan 20 01:48:49.132: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061809976s
Jan 20 01:48:51.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06491335s
Jan 20 01:48:53.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.063817951s
Jan 20 01:48:55.133: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062472109s
... skipping 26 lines ...
Jan 20 01:49:49.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.063725837s
Jan 20 01:49:51.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.064206319s
Jan 20 01:49:53.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m8.064729219s
Jan 20 01:49:55.133: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.0623599s
Jan 20 01:49:57.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m12.063211927s
STEP: Saw pod success 01/20/23 01:49:57.134
Jan 20 01:49:57.134: INFO: Pod "azuredisk-volume-tester-ps6vr" satisfied condition "Succeeded or Failed"
Jan 20 01:49:57.134: INFO: deleting Pod "azuredisk-5168"/"azuredisk-volume-tester-ps6vr"
Jan 20 01:49:57.194: INFO: Pod azuredisk-volume-tester-ps6vr has the following logs: hello world

STEP: Deleting pod azuredisk-volume-tester-ps6vr in namespace azuredisk-5168 01/20/23 01:49:57.194
Jan 20 01:49:57.240: INFO: deleting PVC "azuredisk-5168"/"pvc-tt6th"
Jan 20 01:49:57.240: INFO: Deleting PersistentVolumeClaim "pvc-tt6th"
... skipping 40 lines ...
    STEP: checking the PVC 01/20/23 01:48:44.973
    STEP: validating provisioned PV 01/20/23 01:48:45.002
    STEP: checking the PV 01/20/23 01:48:45.03
    STEP: setting up the pod 01/20/23 01:48:45.03
    I0120 01:48:45.030959   16025 resource_setup.go:62] adding PV (pvc-f319c7a5-6e02-4afe-bfd8-503120da2c75) to pod ()
    STEP: deploying the pod 01/20/23 01:48:45.03
    STEP: checking that the pod's command exits with no error 01/20/23 01:48:45.07
    Jan 20 01:48:45.071: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ps6vr" in namespace "azuredisk-5168" to be "Succeeded or Failed"
    Jan 20 01:48:45.103: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 32.581237ms
    Jan 20 01:48:47.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063809408s
    Jan 20 01:48:49.132: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061809976s
    Jan 20 01:48:51.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06491335s
    Jan 20 01:48:53.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.063817951s
    Jan 20 01:48:55.133: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062472109s
... skipping 26 lines ...
    Jan 20 01:49:49.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.063725837s
    Jan 20 01:49:51.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.064206319s
    Jan 20 01:49:53.135: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m8.064729219s
    Jan 20 01:49:55.133: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.0623599s
    Jan 20 01:49:57.134: INFO: Pod "azuredisk-volume-tester-ps6vr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m12.063211927s
    STEP: Saw pod success 01/20/23 01:49:57.134
    Jan 20 01:49:57.134: INFO: Pod "azuredisk-volume-tester-ps6vr" satisfied condition "Succeeded or Failed"
    Jan 20 01:49:57.134: INFO: deleting Pod "azuredisk-5168"/"azuredisk-volume-tester-ps6vr"
    Jan 20 01:49:57.194: INFO: Pod azuredisk-volume-tester-ps6vr has the following logs: hello world

    STEP: Deleting pod azuredisk-volume-tester-ps6vr in namespace azuredisk-5168 01/20/23 01:49:57.194
    Jan 20 01:49:57.240: INFO: deleting PVC "azuredisk-5168"/"pvc-tt6th"
    Jan 20 01:49:57.240: INFO: Deleting PersistentVolumeClaim "pvc-tt6th"
... skipping 38 lines ...
Jan 20 01:50:40.311: INFO: PersistentVolumeClaim pvc-lxsqt found but phase is Pending instead of Bound.
Jan 20 01:50:42.343: INFO: PersistentVolumeClaim pvc-lxsqt found and phase=Bound (4.094201846s)
STEP: checking the PVC 01/20/23 01:50:42.343
STEP: validating provisioned PV 01/20/23 01:50:42.371
STEP: checking the PV 01/20/23 01:50:42.404
STEP: deploying the pod 01/20/23 01:50:42.404
STEP: checking that the pods command exits with no error 01/20/23 01:50:42.438
Jan 20 01:50:42.438: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-mhdwd" in namespace "azuredisk-4680" to be "Succeeded or Failed"
Jan 20 01:50:42.477: INFO: Pod "azuredisk-volume-tester-mhdwd": Phase="Pending", Reason="", readiness=false. Elapsed: 38.641429ms
Jan 20 01:50:44.506: INFO: Pod "azuredisk-volume-tester-mhdwd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.06807137s
Jan 20 01:50:46.506: INFO: Pod "azuredisk-volume-tester-mhdwd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.068353931s
{"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-20T01:50:46Z"}
++ early_exit_handler
++ '[' -n 171 ']'
++ kill -TERM 171
++ cleanup_dind
++ [[ true == \t\r\u\e ]]
++ echo 'Cleaning up after docker'
... skipping 4 lines ...