kubernetes-sigs/azuredisk-csi-driver PR #1693 pull-azuredisk-csi-driver-e2e-capz-mainv2 #1615847244764811264
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | hccheng72: [V2] fix: prevent requesting replica attachment in a row for one volume |
| Result | ABORTED |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 1h21m |
| Revision | d8ba0aca670d0c02f92f6a79df1d42fdac692933 |
| Refs |
1693 |
... skipping 785 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 222 lines ... 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 11345 100 11345 0 0 175k 0 --:--:-- --:--:-- --:--:-- 178k 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 capzci.azurecr.io/azuredisk-csi:latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d || make container-all push-manifest Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d not found: manifest unknown: manifest tagged by "latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d" is not found make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver' CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=e549890dfb2509639488eabe74ec6eabdacdbd4d -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2023-01-18T23:22:26Z -extldflags "-static"" -tags azurediskv2 -mod vendor -o _output/amd64/azurediskpluginv2.exe ./pkg/azurediskplugin docker buildx rm container-builder || true ERROR: no builder "container-builder" found docker buildx create --use --name=container-builder container-builder # enable qemu for arm64 build # https://github.com/docker/buildx/issues/464#issuecomment-741507760 docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64 Unable to find image 'tonistiigi/binfmt:latest' locally ... skipping 706 lines ... } } ] } make[2]: Leaving directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver' docker pull capzci.azurecr.io/azdiskschedulerextender-csi:latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d || make azdiskschedulerextender-all push-manifest-azdiskschedulerextender Error response from daemon: manifest for capzci.azurecr.io/azdiskschedulerextender-csi:latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d not found: manifest unknown: manifest tagged by "latest-v2-e549890dfb2509639488eabe74ec6eabdacdbd4d" is not found make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver' docker buildx rm container-builder || true container-builder removed docker buildx create --use --name=container-builder container-builder # enable qemu for arm64 build ... skipping 1032 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 1069 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 295 lines ... Jan 18 23:33:37.789: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-vvqjg] to have phase Bound Jan 18 23:33:37.817: INFO: PersistentVolumeClaim pvc-vvqjg found and phase=Bound (28.090054ms) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:33:37.817[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:33:37.845[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:33:37.879[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:33:37.879[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m01/18/23 23:33:37.909[0m Jan 18 23:33:37.909: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-2ntnp" in namespace "azuredisk-2785" to be "Error status code" Jan 18 23:33:37.937: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 27.562237ms Jan 18 23:33:39.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057375697s Jan 18 23:33:41.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059226024s Jan 18 23:33:43.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057666564s Jan 18 23:33:45.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.057427423s Jan 18 23:33:47.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059590326s Jan 18 23:33:49.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Running", Reason="", readiness=true. Elapsed: 12.059638389s Jan 18 23:33:51.971: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Failed", Reason="", readiness=false. Elapsed: 14.061368837s [1mSTEP:[0m Saw pod failure [38;5;243m01/18/23 23:33:51.971[0m Jan 18 23:33:51.971: INFO: Pod "azuredisk-volume-tester-2ntnp" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/18/23 23:33:51.971[0m Jan 18 23:33:52.017: INFO: deleting Pod "azuredisk-2785"/"azuredisk-volume-tester-2ntnp" Jan 18 23:33:52.046: INFO: Pod azuredisk-volume-tester-2ntnp has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-2ntnp in namespace azuredisk-2785 [38;5;243m01/18/23 23:33:52.046[0m Jan 18 23:33:52.091: INFO: deleting PVC "azuredisk-2785"/"pvc-vvqjg" ... skipping 37 lines ... Jan 18 23:33:37.789: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-vvqjg] to have phase Bound Jan 18 23:33:37.817: INFO: PersistentVolumeClaim pvc-vvqjg found and phase=Bound (28.090054ms) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:33:37.817[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:33:37.845[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:33:37.879[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:33:37.879[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m01/18/23 23:33:37.909[0m Jan 18 23:33:37.909: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-2ntnp" in namespace "azuredisk-2785" to be "Error status code" Jan 18 23:33:37.937: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 27.562237ms Jan 18 23:33:39.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057375697s Jan 18 23:33:41.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059226024s Jan 18 23:33:43.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057666564s Jan 18 23:33:45.967: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.057427423s Jan 18 23:33:47.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059590326s Jan 18 23:33:49.969: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Running", Reason="", readiness=true. Elapsed: 12.059638389s Jan 18 23:33:51.971: INFO: Pod "azuredisk-volume-tester-2ntnp": Phase="Failed", Reason="", readiness=false. Elapsed: 14.061368837s [1mSTEP:[0m Saw pod failure [38;5;243m01/18/23 23:33:51.971[0m Jan 18 23:33:51.971: INFO: Pod "azuredisk-volume-tester-2ntnp" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/18/23 23:33:51.971[0m Jan 18 23:33:52.017: INFO: deleting Pod "azuredisk-2785"/"azuredisk-volume-tester-2ntnp" Jan 18 23:33:52.046: INFO: Pod azuredisk-volume-tester-2ntnp has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-2ntnp in namespace azuredisk-2785 [38;5;243m01/18/23 23:33:52.046[0m Jan 18 23:33:52.091: INFO: deleting PVC "azuredisk-2785"/"pvc-vvqjg" ... skipping 66 lines ... Jan 18 23:34:34.541: INFO: PersistentVolumeClaim pvc-cxttc found and phase=Bound (27.794454ms) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:34:34.541[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:34:34.57[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:34:34.598[0m [1mSTEP:[0m attaching disk to node#0 [38;5;243m01/18/23 23:34:34.642[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:34:46.946[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:34:46.983[0m Jan 18 23:34:46.983: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gtsf7" in namespace "azuredisk-7948" to be "Succeeded or Failed" Jan 18 23:34:47.011: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 27.583548ms Jan 18 23:34:49.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05813856s Jan 18 23:34:51.040: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.056775393s Jan 18 23:34:53.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058749941s Jan 18 23:34:55.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058266214s Jan 18 23:34:57.040: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056570814s ... skipping 6 lines ... Jan 18 23:35:11.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 24.058288183s Jan 18 23:35:13.041: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 26.057682166s Jan 18 23:35:15.044: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 28.060146527s Jan 18 23:35:17.041: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 30.057397386s Jan 18 23:35:19.043: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 32.059535247s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:35:19.043[0m Jan 18 23:35:19.043: INFO: Pod "azuredisk-volume-tester-gtsf7" satisfied condition "Succeeded or Failed" Jan 18 23:35:19.043: INFO: deleting Pod "azuredisk-7948"/"azuredisk-volume-tester-gtsf7" Jan 18 23:35:19.075: INFO: Pod azuredisk-volume-tester-gtsf7 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-gtsf7 in namespace azuredisk-7948 [38;5;243m01/18/23 23:35:19.075[0m Jan 18 23:35:19.183: INFO: deleting PVC "azuredisk-7948"/"pvc-cxttc" Jan 18 23:35:19.183: INFO: Deleting PersistentVolumeClaim "pvc-cxttc" ... skipping 37 lines ... Jan 18 23:34:34.541: INFO: PersistentVolumeClaim pvc-cxttc found and phase=Bound (27.794454ms) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:34:34.541[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:34:34.57[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:34:34.598[0m [1mSTEP:[0m attaching disk to node#0 [38;5;243m01/18/23 23:34:34.642[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:34:46.946[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:34:46.983[0m Jan 18 23:34:46.983: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gtsf7" in namespace "azuredisk-7948" to be "Succeeded or Failed" Jan 18 23:34:47.011: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 27.583548ms Jan 18 23:34:49.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.05813856s Jan 18 23:34:51.040: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.056775393s Jan 18 23:34:53.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058749941s Jan 18 23:34:55.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058266214s Jan 18 23:34:57.040: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056570814s ... skipping 6 lines ... Jan 18 23:35:11.042: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 24.058288183s Jan 18 23:35:13.041: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 26.057682166s Jan 18 23:35:15.044: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 28.060146527s Jan 18 23:35:17.041: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Pending", Reason="", readiness=false. Elapsed: 30.057397386s Jan 18 23:35:19.043: INFO: Pod "azuredisk-volume-tester-gtsf7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 32.059535247s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:35:19.043[0m Jan 18 23:35:19.043: INFO: Pod "azuredisk-volume-tester-gtsf7" satisfied condition "Succeeded or Failed" Jan 18 23:35:19.043: INFO: deleting Pod "azuredisk-7948"/"azuredisk-volume-tester-gtsf7" Jan 18 23:35:19.075: INFO: Pod azuredisk-volume-tester-gtsf7 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-gtsf7 in namespace azuredisk-7948 [38;5;243m01/18/23 23:35:19.075[0m Jan 18 23:35:19.183: INFO: deleting PVC "azuredisk-7948"/"pvc-cxttc" Jan 18 23:35:19.183: INFO: Deleting PersistentVolumeClaim "pvc-cxttc" ... skipping 380 lines ... [38;5;243m<< End Captured GinkgoWriter Output[0m [38;5;14mtest case is only available for csi driver[0m [38;5;14mIn [1m[It][0m[38;5;14m at: [1m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:395[0m [1mThere were additional failures detected after the initial failure:[0m [38;5;9m[FAILED][0m [38;5;9mpre-provisioning disk got deleted with the deletion of pv: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: { "error": { "code": "NotFound", "message": "Disk shared-disk-replicas is not found." } }[0m [38;5;9mIn [1m[AfterEach][0m[38;5;9m at: [1m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:490[0m [38;5;243m------------------------------[0m ... skipping 51 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:43:45.778[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:43:45.806[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:43:45.836[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:43:45.836[0m I0118 23:43:45.836342 41604 resource_setup.go:62] adding PV (pvc-6f9546c1-f6d7-418b-953b-0471dcf68507) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:43:45.836[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:43:45.865[0m Jan 18 23:43:45.866: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-v5wpk" in namespace "azuredisk-9514" to be "Succeeded or Failed" Jan 18 23:43:45.894: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 28.698866ms Jan 18 23:43:47.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059328519s Jan 18 23:43:49.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05982936s Jan 18 23:43:51.928: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06215487s Jan 18 23:43:53.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.0592309s Jan 18 23:43:55.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058874809s Jan 18 23:43:57.926: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 12.060577118s Jan 18 23:43:59.927: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.061724029s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:43:59.927[0m Jan 18 23:43:59.928: INFO: Pod "azuredisk-volume-tester-v5wpk" satisfied condition "Succeeded or Failed" Jan 18 23:43:59.928: INFO: deleting Pod "azuredisk-9514"/"azuredisk-volume-tester-v5wpk" Jan 18 23:43:59.970: INFO: Pod azuredisk-volume-tester-v5wpk has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-v5wpk in namespace azuredisk-9514 [38;5;243m01/18/23 23:43:59.97[0m Jan 18 23:44:00.004: INFO: deleting PVC "azuredisk-9514"/"pvc-vszjg" Jan 18 23:44:00.005: INFO: Deleting PersistentVolumeClaim "pvc-vszjg" ... skipping 40 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:43:45.778[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:43:45.806[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:43:45.836[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:43:45.836[0m I0118 23:43:45.836342 41604 resource_setup.go:62] adding PV (pvc-6f9546c1-f6d7-418b-953b-0471dcf68507) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:43:45.836[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:43:45.865[0m Jan 18 23:43:45.866: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-v5wpk" in namespace "azuredisk-9514" to be "Succeeded or Failed" Jan 18 23:43:45.894: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 28.698866ms Jan 18 23:43:47.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059328519s Jan 18 23:43:49.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05982936s Jan 18 23:43:51.928: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06215487s Jan 18 23:43:53.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.0592309s Jan 18 23:43:55.925: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058874809s Jan 18 23:43:57.926: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Pending", Reason="", readiness=false. Elapsed: 12.060577118s Jan 18 23:43:59.927: INFO: Pod "azuredisk-volume-tester-v5wpk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.061724029s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:43:59.927[0m Jan 18 23:43:59.928: INFO: Pod "azuredisk-volume-tester-v5wpk" satisfied condition "Succeeded or Failed" Jan 18 23:43:59.928: INFO: deleting Pod "azuredisk-9514"/"azuredisk-volume-tester-v5wpk" Jan 18 23:43:59.970: INFO: Pod azuredisk-volume-tester-v5wpk has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-v5wpk in namespace azuredisk-9514 [38;5;243m01/18/23 23:43:59.97[0m Jan 18 23:44:00.004: INFO: deleting PVC "azuredisk-9514"/"pvc-vszjg" Jan 18 23:44:00.005: INFO: Deleting PersistentVolumeClaim "pvc-vszjg" ... skipping 37 lines ... Jan 18 23:44:43.345: INFO: PersistentVolumeClaim pvc-h74k2 found but phase is Pending instead of Bound. Jan 18 23:44:45.375: INFO: PersistentVolumeClaim pvc-h74k2 found and phase=Bound (4.091053756s) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:44:45.375[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:44:45.403[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:44:45.432[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:44:45.432[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/18/23 23:44:45.463[0m Jan 18 23:44:45.463: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kqdrl" in namespace "azuredisk-3145" to be "Succeeded or Failed" Jan 18 23:44:45.496: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 32.575896ms Jan 18 23:44:47.526: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.06286521s Jan 18 23:44:49.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.064156935s Jan 18 23:44:51.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062147196s Jan 18 23:44:53.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062343844s Jan 18 23:44:55.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062369319s Jan 18 23:44:57.526: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 12.062975649s Jan 18 23:44:59.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062096436s Jan 18 23:45:01.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Running", Reason="", readiness=true. Elapsed: 16.064419007s Jan 18 23:45:03.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Running", Reason="", readiness=false. Elapsed: 18.063726441s Jan 18 23:45:05.529: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.065731111s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:45:05.529[0m Jan 18 23:45:05.529: INFO: Pod "azuredisk-volume-tester-kqdrl" satisfied condition "Succeeded or Failed" Jan 18 23:45:05.529: INFO: deleting Pod "azuredisk-3145"/"azuredisk-volume-tester-kqdrl" Jan 18 23:45:05.559: INFO: Pod azuredisk-volume-tester-kqdrl has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kqdrl in namespace azuredisk-3145 [38;5;243m01/18/23 23:45:05.559[0m Jan 18 23:45:05.596: INFO: deleting PVC "azuredisk-3145"/"pvc-h74k2" Jan 18 23:45:05.596: INFO: Deleting PersistentVolumeClaim "pvc-h74k2" ... skipping 38 lines ... Jan 18 23:44:43.345: INFO: PersistentVolumeClaim pvc-h74k2 found but phase is Pending instead of Bound. Jan 18 23:44:45.375: INFO: PersistentVolumeClaim pvc-h74k2 found and phase=Bound (4.091053756s) [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:44:45.375[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:44:45.403[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:44:45.432[0m [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:44:45.432[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m01/18/23 23:44:45.463[0m Jan 18 23:44:45.463: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kqdrl" in namespace "azuredisk-3145" to be "Succeeded or Failed" Jan 18 23:44:45.496: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 32.575896ms Jan 18 23:44:47.526: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.06286521s Jan 18 23:44:49.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.064156935s Jan 18 23:44:51.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062147196s Jan 18 23:44:53.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062343844s Jan 18 23:44:55.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062369319s Jan 18 23:44:57.526: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 12.062975649s Jan 18 23:44:59.525: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062096436s Jan 18 23:45:01.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Running", Reason="", readiness=true. Elapsed: 16.064419007s Jan 18 23:45:03.527: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Running", Reason="", readiness=false. Elapsed: 18.063726441s Jan 18 23:45:05.529: INFO: Pod "azuredisk-volume-tester-kqdrl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.065731111s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:45:05.529[0m Jan 18 23:45:05.529: INFO: Pod "azuredisk-volume-tester-kqdrl" satisfied condition "Succeeded or Failed" Jan 18 23:45:05.529: INFO: deleting Pod "azuredisk-3145"/"azuredisk-volume-tester-kqdrl" Jan 18 23:45:05.559: INFO: Pod azuredisk-volume-tester-kqdrl has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kqdrl in namespace azuredisk-3145 [38;5;243m01/18/23 23:45:05.559[0m Jan 18 23:45:05.596: INFO: deleting PVC "azuredisk-3145"/"pvc-h74k2" Jan 18 23:45:05.596: INFO: Deleting PersistentVolumeClaim "pvc-h74k2" ... skipping 39 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:45:51.113[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:45:51.141[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:45:51.17[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:45:51.17[0m I0118 23:45:51.170791 41604 resource_setup.go:62] adding PV (pvc-f732848b-16c4-4bd5-9aff-0beedebb71bf) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:45:51.17[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:45:51.2[0m Jan 18 23:45:51.200: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5q46x" in namespace "azuredisk-7203" to be "Succeeded or Failed" Jan 18 23:45:51.228: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 27.827846ms Jan 18 23:45:53.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059036059s Jan 18 23:45:55.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058516296s Jan 18 23:45:57.258: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058108258s Jan 18 23:45:59.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058494415s Jan 18 23:46:01.258: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057699552s ... skipping 12 lines ... Jan 18 23:46:27.260: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 36.060253865s Jan 18 23:46:29.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 38.05829337s Jan 18 23:46:31.261: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 40.060456349s Jan 18 23:46:33.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 42.058372661s Jan 18 23:46:35.260: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.060122492s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:46:35.26[0m Jan 18 23:46:35.260: INFO: Pod "azuredisk-volume-tester-5q46x" satisfied condition "Succeeded or Failed" Jan 18 23:46:35.261: INFO: deleting Pod "azuredisk-7203"/"azuredisk-volume-tester-5q46x" Jan 18 23:46:35.291: INFO: Pod azuredisk-volume-tester-5q46x has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5q46x in namespace azuredisk-7203 [38;5;243m01/18/23 23:46:35.291[0m Jan 18 23:46:35.329: INFO: deleting PVC "azuredisk-7203"/"pvc-tb9l5" Jan 18 23:46:35.329: INFO: Deleting PersistentVolumeClaim "pvc-tb9l5" ... skipping 40 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:45:51.113[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:45:51.141[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:45:51.17[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:45:51.17[0m I0118 23:45:51.170791 41604 resource_setup.go:62] adding PV (pvc-f732848b-16c4-4bd5-9aff-0beedebb71bf) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:45:51.17[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:45:51.2[0m Jan 18 23:45:51.200: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5q46x" in namespace "azuredisk-7203" to be "Succeeded or Failed" Jan 18 23:45:51.228: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 27.827846ms Jan 18 23:45:53.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059036059s Jan 18 23:45:55.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058516296s Jan 18 23:45:57.258: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058108258s Jan 18 23:45:59.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058494415s Jan 18 23:46:01.258: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057699552s ... skipping 12 lines ... Jan 18 23:46:27.260: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 36.060253865s Jan 18 23:46:29.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 38.05829337s Jan 18 23:46:31.261: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 40.060456349s Jan 18 23:46:33.259: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Pending", Reason="", readiness=false. Elapsed: 42.058372661s Jan 18 23:46:35.260: INFO: Pod "azuredisk-volume-tester-5q46x": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.060122492s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:46:35.26[0m Jan 18 23:46:35.260: INFO: Pod "azuredisk-volume-tester-5q46x" satisfied condition "Succeeded or Failed" Jan 18 23:46:35.261: INFO: deleting Pod "azuredisk-7203"/"azuredisk-volume-tester-5q46x" Jan 18 23:46:35.291: INFO: Pod azuredisk-volume-tester-5q46x has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5q46x in namespace azuredisk-7203 [38;5;243m01/18/23 23:46:35.291[0m Jan 18 23:46:35.329: INFO: deleting PVC "azuredisk-7203"/"pvc-tb9l5" Jan 18 23:46:35.329: INFO: Deleting PersistentVolumeClaim "pvc-tb9l5" ... skipping 39 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:47:20.5[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:47:20.528[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:47:20.557[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:47:20.557[0m I0118 23:47:20.557652 41604 resource_setup.go:62] adding PV (pvc-bc7bdb28-d0ee-469f-8807-71e17cce33ae) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:47:20.557[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:47:20.587[0m Jan 18 23:47:20.587: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-8dtr5" in namespace "azuredisk-1799" to be "Succeeded or Failed" Jan 18 23:47:20.617: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 29.826469ms Jan 18 23:47:22.652: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064993873s Jan 18 23:47:24.645: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05844073s Jan 18 23:47:26.645: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058667343s Jan 18 23:47:28.646: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058842623s Jan 18 23:47:30.646: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05927482s ... skipping 3 lines ... Jan 18 23:47:38.649: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 18.062045659s Jan 18 23:47:40.648: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 20.061403056s Jan 18 23:47:42.650: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 22.063356101s Jan 18 23:47:44.647: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 24.060607175s Jan 18 23:47:46.648: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.061484634s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:47:46.648[0m Jan 18 23:47:46.648: INFO: Pod "azuredisk-volume-tester-8dtr5" satisfied condition "Succeeded or Failed" Jan 18 23:47:46.648: INFO: deleting Pod "azuredisk-1799"/"azuredisk-volume-tester-8dtr5" Jan 18 23:47:46.678: INFO: Pod azuredisk-volume-tester-8dtr5 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8dtr5 in namespace azuredisk-1799 [38;5;243m01/18/23 23:47:46.678[0m Jan 18 23:47:46.719: INFO: deleting PVC "azuredisk-1799"/"pvc-g8z7w" Jan 18 23:47:46.719: INFO: Deleting PersistentVolumeClaim "pvc-g8z7w" ... skipping 40 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:47:20.5[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:47:20.528[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:47:20.557[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:47:20.557[0m I0118 23:47:20.557652 41604 resource_setup.go:62] adding PV (pvc-bc7bdb28-d0ee-469f-8807-71e17cce33ae) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:47:20.557[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:47:20.587[0m Jan 18 23:47:20.587: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-8dtr5" in namespace "azuredisk-1799" to be "Succeeded or Failed" Jan 18 23:47:20.617: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 29.826469ms Jan 18 23:47:22.652: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064993873s Jan 18 23:47:24.645: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.05844073s Jan 18 23:47:26.645: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058667343s Jan 18 23:47:28.646: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058842623s Jan 18 23:47:30.646: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05927482s ... skipping 3 lines ... Jan 18 23:47:38.649: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 18.062045659s Jan 18 23:47:40.648: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 20.061403056s Jan 18 23:47:42.650: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 22.063356101s Jan 18 23:47:44.647: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Pending", Reason="", readiness=false. Elapsed: 24.060607175s Jan 18 23:47:46.648: INFO: Pod "azuredisk-volume-tester-8dtr5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.061484634s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:47:46.648[0m Jan 18 23:47:46.648: INFO: Pod "azuredisk-volume-tester-8dtr5" satisfied condition "Succeeded or Failed" Jan 18 23:47:46.648: INFO: deleting Pod "azuredisk-1799"/"azuredisk-volume-tester-8dtr5" Jan 18 23:47:46.678: INFO: Pod azuredisk-volume-tester-8dtr5 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8dtr5 in namespace azuredisk-1799 [38;5;243m01/18/23 23:47:46.678[0m Jan 18 23:47:46.719: INFO: deleting PVC "azuredisk-1799"/"pvc-g8z7w" Jan 18 23:47:46.719: INFO: Deleting PersistentVolumeClaim "pvc-g8z7w" ... skipping 41 lines ... [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:48:31.865[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:48:31.865[0m I0118 23:48:31.865640 41604 resource_setup.go:62] adding PV (pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:48:31.865[0m [1mSTEP:[0m checking that the pod has 'FailedMount' event [38;5;243m01/18/23 23:48:31.895[0m Jan 18 23:48:43.956: INFO: deleting Pod "azuredisk-6989"/"azuredisk-volume-tester-tjp8f" Jan 18 23:48:43.986: INFO: Error getting logs for pod azuredisk-volume-tester-tjp8f: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-tjp8f) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-tjp8f in namespace azuredisk-6989 [38;5;243m01/18/23 23:48:43.987[0m Jan 18 23:48:44.017: INFO: deleting PVC "azuredisk-6989"/"pvc-4779f" Jan 18 23:48:44.017: INFO: Deleting PersistentVolumeClaim "pvc-4779f" [1mSTEP:[0m waiting for claim's PV "pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3" to be deleted [38;5;243m01/18/23 23:48:44.052[0m Jan 18 23:48:44.052: INFO: Waiting up to 10m0s for PersistentVolume pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3 to get deleted Jan 18 23:48:44.080: INFO: PersistentVolume pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3 found and phase=Bound (28.081068ms) ... skipping 61 lines ... [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:48:31.865[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:48:31.865[0m I0118 23:48:31.865640 41604 resource_setup.go:62] adding PV (pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:48:31.865[0m [1mSTEP:[0m checking that the pod has 'FailedMount' event [38;5;243m01/18/23 23:48:31.895[0m Jan 18 23:48:43.956: INFO: deleting Pod "azuredisk-6989"/"azuredisk-volume-tester-tjp8f" Jan 18 23:48:43.986: INFO: Error getting logs for pod azuredisk-volume-tester-tjp8f: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-tjp8f) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-tjp8f in namespace azuredisk-6989 [38;5;243m01/18/23 23:48:43.987[0m Jan 18 23:48:44.017: INFO: deleting PVC "azuredisk-6989"/"pvc-4779f" Jan 18 23:48:44.017: INFO: Deleting PersistentVolumeClaim "pvc-4779f" [1mSTEP:[0m waiting for claim's PV "pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3" to be deleted [38;5;243m01/18/23 23:48:44.052[0m Jan 18 23:48:44.052: INFO: Waiting up to 10m0s for PersistentVolume pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3 to get deleted Jan 18 23:48:44.080: INFO: PersistentVolume pvc-c2ff066c-71ad-4444-9de0-299cff90b0c3 found and phase=Bound (28.081068ms) ... skipping 58 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:51:19.817[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:51:19.846[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:51:19.874[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:51:19.874[0m I0118 23:51:19.874586 41604 resource_setup.go:62] adding PV (pvc-3e9f28d9-9043-4fda-be4f-4b332ba4e23a) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:51:19.874[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:51:19.904[0m Jan 18 23:51:19.905: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-84drm" in namespace "azuredisk-3439" to be "Succeeded or Failed" Jan 18 23:51:19.937: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 32.320258ms Jan 18 23:51:21.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.062800719s Jan 18 23:51:23.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.062077447s Jan 18 23:51:25.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062525507s Jan 18 23:51:27.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062630848s Jan 18 23:51:29.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062424982s Jan 18 23:51:31.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 12.063194546s Jan 18 23:51:33.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062742953s Jan 18 23:51:35.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Running", Reason="", readiness=true. Elapsed: 16.063697833s Jan 18 23:51:37.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Running", Reason="", readiness=false. Elapsed: 18.06304202s Jan 18 23:51:39.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.062906294s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:51:39.968[0m Jan 18 23:51:39.968: INFO: Pod "azuredisk-volume-tester-84drm" satisfied condition "Succeeded or Failed" Jan 18 23:51:39.968: INFO: deleting Pod "azuredisk-3439"/"azuredisk-volume-tester-84drm" Jan 18 23:51:40.014: INFO: Pod azuredisk-volume-tester-84drm has the following logs: e2e-test [1mSTEP:[0m Deleting pod azuredisk-volume-tester-84drm in namespace azuredisk-3439 [38;5;243m01/18/23 23:51:40.014[0m Jan 18 23:51:40.057: INFO: deleting PVC "azuredisk-3439"/"pvc-l68rm" Jan 18 23:51:40.057: INFO: Deleting PersistentVolumeClaim "pvc-l68rm" ... skipping 40 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:51:19.817[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:51:19.846[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:51:19.874[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:51:19.874[0m I0118 23:51:19.874586 41604 resource_setup.go:62] adding PV (pvc-3e9f28d9-9043-4fda-be4f-4b332ba4e23a) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:51:19.874[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/18/23 23:51:19.904[0m Jan 18 23:51:19.905: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-84drm" in namespace "azuredisk-3439" to be "Succeeded or Failed" Jan 18 23:51:19.937: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 32.320258ms Jan 18 23:51:21.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.062800719s Jan 18 23:51:23.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.062077447s Jan 18 23:51:25.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062525507s Jan 18 23:51:27.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062630848s Jan 18 23:51:29.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.062424982s Jan 18 23:51:31.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 12.063194546s Jan 18 23:51:33.967: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062742953s Jan 18 23:51:35.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Running", Reason="", readiness=true. Elapsed: 16.063697833s Jan 18 23:51:37.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Running", Reason="", readiness=false. Elapsed: 18.06304202s Jan 18 23:51:39.968: INFO: Pod "azuredisk-volume-tester-84drm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.062906294s [1mSTEP:[0m Saw pod success [38;5;243m01/18/23 23:51:39.968[0m Jan 18 23:51:39.968: INFO: Pod "azuredisk-volume-tester-84drm" satisfied condition "Succeeded or Failed" Jan 18 23:51:39.968: INFO: deleting Pod "azuredisk-3439"/"azuredisk-volume-tester-84drm" Jan 18 23:51:40.014: INFO: Pod azuredisk-volume-tester-84drm has the following logs: e2e-test [1mSTEP:[0m Deleting pod azuredisk-volume-tester-84drm in namespace azuredisk-3439 [38;5;243m01/18/23 23:51:40.014[0m Jan 18 23:51:40.057: INFO: deleting PVC "azuredisk-3439"/"pvc-l68rm" Jan 18 23:51:40.057: INFO: Deleting PersistentVolumeClaim "pvc-l68rm" ... skipping 39 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:52:25.17[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:52:25.198[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:52:25.226[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:52:25.227[0m I0118 23:52:25.227183 41604 resource_setup.go:62] adding PV (pvc-4980edf8-f0bd-44c6-b4c6-e9895fbee6d5) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:52:25.227[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m01/18/23 23:52:25.258[0m Jan 18 23:52:25.258: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-p2sdn" in namespace "azuredisk-900" to be "Error status code" Jan 18 23:52:25.289: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 30.408876ms Jan 18 23:52:27.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060288783s Jan 18 23:52:29.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061038164s Jan 18 23:52:31.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06048032s Jan 18 23:52:33.318: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059646998s Jan 18 23:52:35.318: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059529215s Jan 18 23:52:37.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.060479104s Jan 18 23:52:39.321: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062729695s Jan 18 23:52:41.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 16.061442818s Jan 18 23:52:43.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Failed", Reason="", readiness=false. Elapsed: 18.061421188s [1mSTEP:[0m Saw pod failure [38;5;243m01/18/23 23:52:43.32[0m Jan 18 23:52:43.320: INFO: Pod "azuredisk-volume-tester-p2sdn" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/18/23 23:52:43.32[0m Jan 18 23:52:43.351: INFO: deleting Pod "azuredisk-900"/"azuredisk-volume-tester-p2sdn" Jan 18 23:52:43.385: INFO: Pod azuredisk-volume-tester-p2sdn has the following logs: touch: /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-p2sdn in namespace azuredisk-900 [38;5;243m01/18/23 23:52:43.385[0m Jan 18 23:52:43.423: INFO: deleting PVC "azuredisk-900"/"pvc-86q8c" ... skipping 47 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/18/23 23:52:25.17[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/18/23 23:52:25.198[0m [1mSTEP:[0m checking the PV [38;5;243m01/18/23 23:52:25.226[0m [1mSTEP:[0m setting up the pod [38;5;243m01/18/23 23:52:25.227[0m I0118 23:52:25.227183 41604 resource_setup.go:62] adding PV (pvc-4980edf8-f0bd-44c6-b4c6-e9895fbee6d5) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/18/23 23:52:25.227[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m01/18/23 23:52:25.258[0m Jan 18 23:52:25.258: INFO: Waiting up to 10m0s for pod "azuredisk-volume-tester-p2sdn" in namespace "azuredisk-900" to be "Error status code" Jan 18 23:52:25.289: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 30.408876ms Jan 18 23:52:27.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060288783s Jan 18 23:52:29.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061038164s Jan 18 23:52:31.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06048032s Jan 18 23:52:33.318: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059646998s Jan 18 23:52:35.318: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059529215s Jan 18 23:52:37.319: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.060479104s Jan 18 23:52:39.321: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062729695s Jan 18 23:52:41.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Pending", Reason="", readiness=false. Elapsed: 16.061442818s Jan 18 23:52:43.320: INFO: Pod "azuredisk-volume-tester-p2sdn": Phase="Failed", Reason="", readiness=false. Elapsed: 18.061421188s [1mSTEP:[0m Saw pod failure [38;5;243m01/18/23 23:52:43.32[0m Jan 18 23:52:43.320: INFO: Pod "azuredisk-volume-tester-p2sdn" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m01/18/23 23:52:43.32[0m Jan 18 23:52:43.351: INFO: deleting Pod "azuredisk-900"/"azuredisk-volume-tester-p2sdn" Jan 18 23:52:43.385: INFO: Pod azuredisk-volume-tester-p2sdn has the following logs: touch: /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-p2sdn in namespace azuredisk-900 [38;5;243m01/18/23 23:52:43.385[0m Jan 18 23:52:43.423: INFO: deleting PVC "azuredisk-900"/"pvc-86q8c" ... skipping 684 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:00:48.703[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:00:48.731[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:00:48.759[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:00:48.76[0m I0119 00:00:48.760133 41604 resource_setup.go:62] adding PV (pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:00:48.76[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:00:48.789[0m Jan 19 00:00:48.789: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kdqb8" in namespace "azuredisk-9550" to be "Succeeded or Failed" Jan 19 00:00:48.819: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 29.61722ms Jan 19 00:00:50.848: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059051462s Jan 19 00:00:52.850: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.06053967s Jan 19 00:00:54.848: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058972058s Jan 19 00:00:56.850: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061078793s Jan 19 00:00:58.849: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059767079s Jan 19 00:01:00.851: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Running", Reason="", readiness=true. Elapsed: 12.061757185s Jan 19 00:01:02.854: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Running", Reason="", readiness=false. Elapsed: 14.065270826s Jan 19 00:01:04.851: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.061757216s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:01:04.851[0m Jan 19 00:01:04.851: INFO: Pod "azuredisk-volume-tester-kdqb8" satisfied condition "Succeeded or Failed" Jan 19 00:01:04.880: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-kdqb8" Jan 19 00:01:04.920: INFO: Pod azuredisk-volume-tester-kdqb8 has the following logs: [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kdqb8 in namespace azuredisk-9550 [38;5;243m01/19/23 00:01:04.92[0m [1mSTEP:[0m waiting for disk to detach from node [38;5;243m01/19/23 00:01:04.956[0m [1mSTEP:[0m cloning existing volume [38;5;243m01/19/23 00:01:23.014[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m01/19/23 00:01:23.071[0m ... skipping 6 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:01:27.195[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:01:27.224[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:01:27.252[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:01:27.253[0m I0119 00:01:27.253367 41604 resource_setup.go:62] adding PV (pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b) to pod () [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m01/19/23 00:01:27.253[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:01:27.283[0m Jan 19 00:01:27.284: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-xfss9" in namespace "azuredisk-9550" to be "Succeeded or Failed" Jan 19 00:01:27.314: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 29.623833ms Jan 19 00:01:29.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060152022s Jan 19 00:01:31.343: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059459568s Jan 19 00:01:33.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059536712s Jan 19 00:01:35.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.060657101s Jan 19 00:01:37.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.06030412s Jan 19 00:01:39.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059632844s Jan 19 00:01:41.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Running", Reason="", readiness=false. Elapsed: 14.061334926s Jan 19 00:01:43.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.061174263s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:01:43.345[0m Jan 19 00:01:43.345: INFO: Pod "azuredisk-volume-tester-xfss9" satisfied condition "Succeeded or Failed" Jan 19 00:01:43.345: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-xfss9" Jan 19 00:01:43.376: INFO: Pod azuredisk-volume-tester-xfss9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-xfss9 in namespace azuredisk-9550 [38;5;243m01/19/23 00:01:43.376[0m Jan 19 00:01:43.413: INFO: deleting PVC "azuredisk-9550"/"pvc-rh6zl" Jan 19 00:01:43.413: INFO: Deleting PersistentVolumeClaim "pvc-rh6zl" ... skipping 8 lines ... Jan 19 00:02:13.643: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b found and phase=Released (30.200998251s) Jan 19 00:02:18.671: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b found and phase=Released (35.229463008s) Jan 19 00:02:23.699: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b was removed Jan 19 00:02:23.699: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-rh6zl to be removed Jan 19 00:02:23.727: INFO: Claim "pvc-rh6zl" in namespace "azuredisk-9550" doesn't exist in the system Jan 19 00:02:23.727: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-kdqb8" Jan 19 00:02:23.755: INFO: Error getting logs for pod azuredisk-volume-tester-kdqb8: the server could not find the requested resource (get pods azuredisk-volume-tester-kdqb8) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kdqb8 in namespace azuredisk-9550 [38;5;243m01/19/23 00:02:23.755[0m Jan 19 00:02:23.783: INFO: deleting PVC "azuredisk-9550"/"pvc-xksgc" Jan 19 00:02:23.783: INFO: Deleting PersistentVolumeClaim "pvc-xksgc" [1mSTEP:[0m waiting for claim's PV "pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b" to be deleted [38;5;243m01/19/23 00:02:23.812[0m Jan 19 00:02:23.812: INFO: Waiting up to 10m0s for PersistentVolume pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b to get deleted Jan 19 00:02:23.841: INFO: PersistentVolume pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b found and phase=Released (28.701242ms) ... skipping 31 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:00:48.703[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:00:48.731[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:00:48.759[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:00:48.76[0m I0119 00:00:48.760133 41604 resource_setup.go:62] adding PV (pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:00:48.76[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:00:48.789[0m Jan 19 00:00:48.789: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kdqb8" in namespace "azuredisk-9550" to be "Succeeded or Failed" Jan 19 00:00:48.819: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 29.61722ms Jan 19 00:00:50.848: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059051462s Jan 19 00:00:52.850: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.06053967s Jan 19 00:00:54.848: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058972058s Jan 19 00:00:56.850: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061078793s Jan 19 00:00:58.849: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059767079s Jan 19 00:01:00.851: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Running", Reason="", readiness=true. Elapsed: 12.061757185s Jan 19 00:01:02.854: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Running", Reason="", readiness=false. Elapsed: 14.065270826s Jan 19 00:01:04.851: INFO: Pod "azuredisk-volume-tester-kdqb8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.061757216s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:01:04.851[0m Jan 19 00:01:04.851: INFO: Pod "azuredisk-volume-tester-kdqb8" satisfied condition "Succeeded or Failed" Jan 19 00:01:04.880: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-kdqb8" Jan 19 00:01:04.920: INFO: Pod azuredisk-volume-tester-kdqb8 has the following logs: [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kdqb8 in namespace azuredisk-9550 [38;5;243m01/19/23 00:01:04.92[0m [1mSTEP:[0m waiting for disk to detach from node [38;5;243m01/19/23 00:01:04.956[0m [1mSTEP:[0m cloning existing volume [38;5;243m01/19/23 00:01:23.014[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m01/19/23 00:01:23.071[0m ... skipping 6 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:01:27.195[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:01:27.224[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:01:27.252[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:01:27.253[0m I0119 00:01:27.253367 41604 resource_setup.go:62] adding PV (pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b) to pod () [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m01/19/23 00:01:27.253[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:01:27.283[0m Jan 19 00:01:27.284: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-xfss9" in namespace "azuredisk-9550" to be "Succeeded or Failed" Jan 19 00:01:27.314: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 29.623833ms Jan 19 00:01:29.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.060152022s Jan 19 00:01:31.343: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059459568s Jan 19 00:01:33.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.059536712s Jan 19 00:01:35.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.060657101s Jan 19 00:01:37.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.06030412s Jan 19 00:01:39.344: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059632844s Jan 19 00:01:41.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Running", Reason="", readiness=false. Elapsed: 14.061334926s Jan 19 00:01:43.345: INFO: Pod "azuredisk-volume-tester-xfss9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.061174263s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:01:43.345[0m Jan 19 00:01:43.345: INFO: Pod "azuredisk-volume-tester-xfss9" satisfied condition "Succeeded or Failed" Jan 19 00:01:43.345: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-xfss9" Jan 19 00:01:43.376: INFO: Pod azuredisk-volume-tester-xfss9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-xfss9 in namespace azuredisk-9550 [38;5;243m01/19/23 00:01:43.376[0m Jan 19 00:01:43.413: INFO: deleting PVC "azuredisk-9550"/"pvc-rh6zl" Jan 19 00:01:43.413: INFO: Deleting PersistentVolumeClaim "pvc-rh6zl" ... skipping 8 lines ... Jan 19 00:02:13.643: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b found and phase=Released (30.200998251s) Jan 19 00:02:18.671: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b found and phase=Released (35.229463008s) Jan 19 00:02:23.699: INFO: PersistentVolume pvc-29e87f3f-f6dc-4efe-a7bf-039304f4667b was removed Jan 19 00:02:23.699: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-rh6zl to be removed Jan 19 00:02:23.727: INFO: Claim "pvc-rh6zl" in namespace "azuredisk-9550" doesn't exist in the system Jan 19 00:02:23.727: INFO: deleting Pod "azuredisk-9550"/"azuredisk-volume-tester-kdqb8" Jan 19 00:02:23.755: INFO: Error getting logs for pod azuredisk-volume-tester-kdqb8: the server could not find the requested resource (get pods azuredisk-volume-tester-kdqb8) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kdqb8 in namespace azuredisk-9550 [38;5;243m01/19/23 00:02:23.755[0m Jan 19 00:02:23.783: INFO: deleting PVC "azuredisk-9550"/"pvc-xksgc" Jan 19 00:02:23.783: INFO: Deleting PersistentVolumeClaim "pvc-xksgc" [1mSTEP:[0m waiting for claim's PV "pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b" to be deleted [38;5;243m01/19/23 00:02:23.812[0m Jan 19 00:02:23.812: INFO: Waiting up to 10m0s for PersistentVolume pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b to get deleted Jan 19 00:02:23.841: INFO: PersistentVolume pvc-d1c58ca6-70f0-4f2f-a9ad-7ae35657b23b found and phase=Released (28.701242ms) ... skipping 30 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:02:38.721[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:02:38.749[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:02:38.777[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:02:38.777[0m I0119 00:02:38.777612 41604 resource_setup.go:62] adding PV (pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:02:38.777[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:02:38.807[0m Jan 19 00:02:38.807: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-rd454" in namespace "azuredisk-4676" to be "Succeeded or Failed" Jan 19 00:02:38.837: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 29.848531ms Jan 19 00:02:40.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 2.0593992s Jan 19 00:02:42.868: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 4.060423805s Jan 19 00:02:44.865: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057968867s Jan 19 00:02:46.866: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058532461s Jan 19 00:02:48.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059963612s Jan 19 00:02:50.869: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 12.061606715s Jan 19 00:02:52.868: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 14.061104531s Jan 19 00:02:54.873: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 16.06527413s Jan 19 00:02:56.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059725369s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:02:56.867[0m Jan 19 00:02:56.867: INFO: Pod "azuredisk-volume-tester-rd454" satisfied condition "Succeeded or Failed" Jan 19 00:02:56.896: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-rd454" Jan 19 00:02:56.929: INFO: Pod azuredisk-volume-tester-rd454 has the following logs: [1mSTEP:[0m Deleting pod azuredisk-volume-tester-rd454 in namespace azuredisk-4676 [38;5;243m01/19/23 00:02:56.929[0m [1mSTEP:[0m waiting for disk to detach from node [38;5;243m01/19/23 00:02:56.994[0m [1mSTEP:[0m cloning existing volume [38;5;243m01/19/23 00:03:11.051[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m01/19/23 00:03:11.106[0m ... skipping 6 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:03:15.227[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:03:15.255[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:03:15.283[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:03:15.283[0m I0119 00:03:15.283761 41604 resource_setup.go:62] adding PV (pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f) to pod () [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m01/19/23 00:03:15.283[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:03:15.312[0m Jan 19 00:03:15.312: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4gmjn" in namespace "azuredisk-4676" to be "Succeeded or Failed" Jan 19 00:03:15.345: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 33.331368ms Jan 19 00:03:17.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063125791s Jan 19 00:03:19.377: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.065109826s Jan 19 00:03:21.374: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.061787344s Jan 19 00:03:23.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062896167s Jan 19 00:03:25.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063294631s Jan 19 00:03:27.374: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.062055251s Jan 19 00:03:29.386: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 14.074468968s Jan 19 00:03:31.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 16.06332245s Jan 19 00:03:33.377: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.064792329s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:03:33.377[0m Jan 19 00:03:33.377: INFO: Pod "azuredisk-volume-tester-4gmjn" satisfied condition "Succeeded or Failed" Jan 19 00:03:33.377: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-4gmjn" Jan 19 00:03:33.407: INFO: Pod azuredisk-volume-tester-4gmjn has the following logs: 20.0G [1mSTEP:[0m Deleting pod azuredisk-volume-tester-4gmjn in namespace azuredisk-4676 [38;5;243m01/19/23 00:03:33.408[0m Jan 19 00:03:33.454: INFO: deleting PVC "azuredisk-4676"/"pvc-mgq2l" Jan 19 00:03:33.454: INFO: Deleting PersistentVolumeClaim "pvc-mgq2l" ... skipping 8 lines ... Jan 19 00:04:03.695: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f found and phase=Released (30.211046755s) Jan 19 00:04:08.726: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f found and phase=Released (35.242437429s) Jan 19 00:04:13.756: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f was removed Jan 19 00:04:13.756: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-mgq2l to be removed Jan 19 00:04:13.784: INFO: Claim "pvc-mgq2l" in namespace "azuredisk-4676" doesn't exist in the system Jan 19 00:04:13.784: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-rd454" Jan 19 00:04:13.812: INFO: Error getting logs for pod azuredisk-volume-tester-rd454: the server could not find the requested resource (get pods azuredisk-volume-tester-rd454) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-rd454 in namespace azuredisk-4676 [38;5;243m01/19/23 00:04:13.812[0m Jan 19 00:04:13.840: INFO: deleting PVC "azuredisk-4676"/"pvc-2szc2" Jan 19 00:04:13.840: INFO: Deleting PersistentVolumeClaim "pvc-2szc2" [1mSTEP:[0m waiting for claim's PV "pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9" to be deleted [38;5;243m01/19/23 00:04:13.869[0m Jan 19 00:04:13.869: INFO: Waiting up to 10m0s for PersistentVolume pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9 to get deleted Jan 19 00:04:13.902: INFO: PersistentVolume pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9 found and phase=Released (33.1274ms) ... skipping 31 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:02:38.721[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:02:38.749[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:02:38.777[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:02:38.777[0m I0119 00:02:38.777612 41604 resource_setup.go:62] adding PV (pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:02:38.777[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:02:38.807[0m Jan 19 00:02:38.807: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-rd454" in namespace "azuredisk-4676" to be "Succeeded or Failed" Jan 19 00:02:38.837: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 29.848531ms Jan 19 00:02:40.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 2.0593992s Jan 19 00:02:42.868: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 4.060423805s Jan 19 00:02:44.865: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057968867s Jan 19 00:02:46.866: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 8.058532461s Jan 19 00:02:48.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059963612s Jan 19 00:02:50.869: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 12.061606715s Jan 19 00:02:52.868: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 14.061104531s Jan 19 00:02:54.873: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Pending", Reason="", readiness=false. Elapsed: 16.06527413s Jan 19 00:02:56.867: INFO: Pod "azuredisk-volume-tester-rd454": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059725369s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:02:56.867[0m Jan 19 00:02:56.867: INFO: Pod "azuredisk-volume-tester-rd454" satisfied condition "Succeeded or Failed" Jan 19 00:02:56.896: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-rd454" Jan 19 00:02:56.929: INFO: Pod azuredisk-volume-tester-rd454 has the following logs: [1mSTEP:[0m Deleting pod azuredisk-volume-tester-rd454 in namespace azuredisk-4676 [38;5;243m01/19/23 00:02:56.929[0m [1mSTEP:[0m waiting for disk to detach from node [38;5;243m01/19/23 00:02:56.994[0m [1mSTEP:[0m cloning existing volume [38;5;243m01/19/23 00:03:11.051[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m01/19/23 00:03:11.106[0m ... skipping 6 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:03:15.227[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:03:15.255[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:03:15.283[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:03:15.283[0m I0119 00:03:15.283761 41604 resource_setup.go:62] adding PV (pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f) to pod () [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m01/19/23 00:03:15.283[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:03:15.312[0m Jan 19 00:03:15.312: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4gmjn" in namespace "azuredisk-4676" to be "Succeeded or Failed" Jan 19 00:03:15.345: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 33.331368ms Jan 19 00:03:17.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063125791s Jan 19 00:03:19.377: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.065109826s Jan 19 00:03:21.374: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.061787344s Jan 19 00:03:23.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062896167s Jan 19 00:03:25.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063294631s Jan 19 00:03:27.374: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.062055251s Jan 19 00:03:29.386: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 14.074468968s Jan 19 00:03:31.375: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Pending", Reason="", readiness=false. Elapsed: 16.06332245s Jan 19 00:03:33.377: INFO: Pod "azuredisk-volume-tester-4gmjn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.064792329s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:03:33.377[0m Jan 19 00:03:33.377: INFO: Pod "azuredisk-volume-tester-4gmjn" satisfied condition "Succeeded or Failed" Jan 19 00:03:33.377: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-4gmjn" Jan 19 00:03:33.407: INFO: Pod azuredisk-volume-tester-4gmjn has the following logs: 20.0G [1mSTEP:[0m Deleting pod azuredisk-volume-tester-4gmjn in namespace azuredisk-4676 [38;5;243m01/19/23 00:03:33.408[0m Jan 19 00:03:33.454: INFO: deleting PVC "azuredisk-4676"/"pvc-mgq2l" Jan 19 00:03:33.454: INFO: Deleting PersistentVolumeClaim "pvc-mgq2l" ... skipping 8 lines ... Jan 19 00:04:03.695: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f found and phase=Released (30.211046755s) Jan 19 00:04:08.726: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f found and phase=Released (35.242437429s) Jan 19 00:04:13.756: INFO: PersistentVolume pvc-82b5214b-0bb1-46e8-89fd-2b9d861e316f was removed Jan 19 00:04:13.756: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-mgq2l to be removed Jan 19 00:04:13.784: INFO: Claim "pvc-mgq2l" in namespace "azuredisk-4676" doesn't exist in the system Jan 19 00:04:13.784: INFO: deleting Pod "azuredisk-4676"/"azuredisk-volume-tester-rd454" Jan 19 00:04:13.812: INFO: Error getting logs for pod azuredisk-volume-tester-rd454: the server could not find the requested resource (get pods azuredisk-volume-tester-rd454) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-rd454 in namespace azuredisk-4676 [38;5;243m01/19/23 00:04:13.812[0m Jan 19 00:04:13.840: INFO: deleting PVC "azuredisk-4676"/"pvc-2szc2" Jan 19 00:04:13.840: INFO: Deleting PersistentVolumeClaim "pvc-2szc2" [1mSTEP:[0m waiting for claim's PV "pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9" to be deleted [38;5;243m01/19/23 00:04:13.869[0m Jan 19 00:04:13.869: INFO: Waiting up to 10m0s for PersistentVolume pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9 to get deleted Jan 19 00:04:13.902: INFO: PersistentVolume pvc-cc5471e5-9896-4bc9-a226-04628fa89ba9 found and phase=Released (33.1274ms) ... skipping 58 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:04:37.185[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:04:37.221[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:04:37.248[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:04:37.248[0m I0119 00:04:37.249153 41604 resource_setup.go:62] adding PV (pvc-dd0f6bdc-be30-455c-985d-01a294c3f027) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:04:37.249[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:04:37.279[0m Jan 19 00:04:37.279: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4bm5q" in namespace "azuredisk-9387" to be "Succeeded or Failed" Jan 19 00:04:37.308: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 28.981083ms Jan 19 00:04:39.339: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059770288s Jan 19 00:04:41.340: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061021481s Jan 19 00:04:43.339: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 6.060382154s Jan 19 00:04:45.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059483257s Jan 19 00:04:47.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059242046s Jan 19 00:04:49.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059052233s Jan 19 00:04:51.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 14.059308099s Jan 19 00:04:53.337: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 16.058687626s Jan 19 00:04:55.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059323606s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:04:55.338[0m Jan 19 00:04:55.338: INFO: Pod "azuredisk-volume-tester-4bm5q" satisfied condition "Succeeded or Failed" Jan 19 00:04:55.338: INFO: deleting Pod "azuredisk-9387"/"azuredisk-volume-tester-4bm5q" Jan 19 00:04:55.369: INFO: Pod azuredisk-volume-tester-4bm5q has the following logs: hello world hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-4bm5q in namespace azuredisk-9387 [38;5;243m01/19/23 00:04:55.369[0m ... skipping 90 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:04:37.185[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:04:37.221[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:04:37.248[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:04:37.248[0m I0119 00:04:37.249153 41604 resource_setup.go:62] adding PV (pvc-dd0f6bdc-be30-455c-985d-01a294c3f027) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:04:37.249[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:04:37.279[0m Jan 19 00:04:37.279: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-4bm5q" in namespace "azuredisk-9387" to be "Succeeded or Failed" Jan 19 00:04:37.308: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 28.981083ms Jan 19 00:04:39.339: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059770288s Jan 19 00:04:41.340: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 4.061021481s Jan 19 00:04:43.339: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 6.060382154s Jan 19 00:04:45.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 8.059483257s Jan 19 00:04:47.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 10.059242046s Jan 19 00:04:49.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059052233s Jan 19 00:04:51.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 14.059308099s Jan 19 00:04:53.337: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Pending", Reason="", readiness=false. Elapsed: 16.058687626s Jan 19 00:04:55.338: INFO: Pod "azuredisk-volume-tester-4bm5q": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059323606s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:04:55.338[0m Jan 19 00:04:55.338: INFO: Pod "azuredisk-volume-tester-4bm5q" satisfied condition "Succeeded or Failed" Jan 19 00:04:55.338: INFO: deleting Pod "azuredisk-9387"/"azuredisk-volume-tester-4bm5q" Jan 19 00:04:55.369: INFO: Pod azuredisk-volume-tester-4bm5q has the following logs: hello world hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-4bm5q in namespace azuredisk-9387 [38;5;243m01/19/23 00:04:55.369[0m ... skipping 75 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:06:05.145[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:06:05.173[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:06:05.203[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:06:05.204[0m I0119 00:06:05.204222 41604 resource_setup.go:62] adding PV (pvc-2bab2d04-558e-4f2b-a670-9d6ea38fe401) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:06:05.204[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:06:05.236[0m Jan 19 00:06:05.236: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7gk2z" in namespace "azuredisk-9529" to be "Succeeded or Failed" Jan 19 00:06:05.264: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 27.953259ms Jan 19 00:06:07.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059232422s Jan 19 00:06:09.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059126824s Jan 19 00:06:11.296: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 6.05991045s Jan 19 00:06:13.299: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062416512s Jan 19 00:06:15.296: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 10.060294772s Jan 19 00:06:17.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059234189s Jan 19 00:06:19.294: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.057740282s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:06:19.294[0m Jan 19 00:06:19.294: INFO: Pod "azuredisk-volume-tester-7gk2z" satisfied condition "Succeeded or Failed" Jan 19 00:06:19.294: INFO: deleting Pod "azuredisk-9529"/"azuredisk-volume-tester-7gk2z" Jan 19 00:06:19.325: INFO: Pod azuredisk-volume-tester-7gk2z has the following logs: 100+0 records in 100+0 records out 104857600 bytes (100.0MB) copied, 0.050276 seconds, 1.9GB/s hello world ... skipping 67 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:06:05.145[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:06:05.173[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:06:05.203[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:06:05.204[0m I0119 00:06:05.204222 41604 resource_setup.go:62] adding PV (pvc-2bab2d04-558e-4f2b-a670-9d6ea38fe401) to pod () [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:06:05.204[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:06:05.236[0m Jan 19 00:06:05.236: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7gk2z" in namespace "azuredisk-9529" to be "Succeeded or Failed" Jan 19 00:06:05.264: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 27.953259ms Jan 19 00:06:07.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059232422s Jan 19 00:06:09.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059126824s Jan 19 00:06:11.296: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 6.05991045s Jan 19 00:06:13.299: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062416512s Jan 19 00:06:15.296: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 10.060294772s Jan 19 00:06:17.295: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Pending", Reason="", readiness=false. Elapsed: 12.059234189s Jan 19 00:06:19.294: INFO: Pod "azuredisk-volume-tester-7gk2z": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.057740282s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:06:19.294[0m Jan 19 00:06:19.294: INFO: Pod "azuredisk-volume-tester-7gk2z" satisfied condition "Succeeded or Failed" Jan 19 00:06:19.294: INFO: deleting Pod "azuredisk-9529"/"azuredisk-volume-tester-7gk2z" Jan 19 00:06:19.325: INFO: Pod azuredisk-volume-tester-7gk2z has the following logs: 100+0 records in 100+0 records out 104857600 bytes (100.0MB) copied, 0.050276 seconds, 1.9GB/s hello world ... skipping 50 lines ... Jan 19 00:07:12.631: INFO: PersistentVolumeClaim pvc-k6n6m found but phase is Pending instead of Bound. Jan 19 00:07:14.661: INFO: PersistentVolumeClaim pvc-k6n6m found and phase=Bound (4.087145743s) [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:07:14.661[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:07:14.689[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:07:14.718[0m [1mSTEP:[0m deploying the pod [38;5;243m01/19/23 00:07:14.718[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:07:14.748[0m Jan 19 00:07:14.748: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5prqk" in namespace "azuredisk-9632" to be "Succeeded or Failed" Jan 19 00:07:14.782: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 33.905934ms Jan 19 00:07:16.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064043049s Jan 19 00:07:18.811: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.063338603s Jan 19 00:07:20.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.064568384s Jan 19 00:07:22.811: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.063101928s Jan 19 00:07:24.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063928448s Jan 19 00:07:26.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 12.064275735s Jan 19 00:07:28.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 14.064517347s Jan 19 00:07:30.812: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Pending", Reason="", readiness=false. Elapsed: 16.064220845s Jan 19 00:07:32.813: INFO: Pod "azuredisk-volume-tester-5prqk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.064893317s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:07:32.813[0m Jan 19 00:07:32.813: INFO: Pod "azuredisk-volume-tester-5prqk" satisfied condition "Succeeded or Failed" Jan 19 00:07:32.841: INFO: deleting Pod "azuredisk-9632"/"azuredisk-volume-tester-5prqk" Jan 19 00:07:32.872: INFO: Pod azuredisk-volume-tester-5prqk has the following logs: [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5prqk in namespace azuredisk-9632 [38;5;243m01/19/23 00:07:32.872[0m [1mSTEP:[0m waiting for disk to detach from node [38;5;243m01/19/23 00:07:32.906[0m [1mSTEP:[0m Checking Prow test resource group [38;5;243m01/19/23 00:07:52.964[0m [1mSTEP:[0m Prow test resource group: capz-sn3zon [38;5;243m01/19/23 00:07:52.965[0m ... skipping 16 lines ... [1mSTEP:[0m checking the PVC [38;5;243m01/19/23 00:08:13.287[0m [1mSTEP:[0m validating provisioned PV [38;5;243m01/19/23 00:08:13.315[0m [1mSTEP:[0m checking the PV [38;5;243m01/19/23 00:08:13.344[0m [1mSTEP:[0m setting up the pod [38;5;243m01/19/23 00:08:13.344[0m I0119 00:08:13.344875 41604 resource_setup.go:62] adding PV (pvc-fb8734c0-b6f4-42b8-9571-32961feef802) to pod () [1mSTEP:[0m deploying a pod with a volume restored from the snapshot [38;5;243m01/19/23 00:08:13.344[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m01/19/23 00:08:13.374[0m Jan 19 00:08:13.374: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-knsh6" in namespace "azuredisk-9632" to be "Succeeded or Failed" Jan 19 00:08:13.407: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 32.799186ms Jan 19 00:08:15.439: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.064711568s Jan 19 00:08:17.440: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.065831712s Jan 19 00:08:19.437: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062650533s Jan 19 00:08:21.437: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.062711293s Jan 19 00:08:23.438: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063519462s Jan 19 00:08:25.438: INFO: Pod "azuredisk-volume-tester-knsh6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.063532235s [1mSTEP:[0m Saw pod success [38;5;243m01/19/23 00:08:25.438[0m Jan 19 00:08:25.438: INFO: Pod "azuredisk-volume-tester-knsh6" satisfied condition "Succeeded or Failed" Jan 19 00:08:25.438: INFO: deleting Pod "azuredisk-9632"/"azuredisk-volume-tester-knsh6" Jan 19 00:08:25.474: INFO: Pod azuredisk-volume-tester-knsh6 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-knsh6 in namespace azuredisk-9632 [38;5;243m01/19/23 00:08:25.474[0m Jan 19 00:08:25.518: INFO: deleting PVC "azuredisk-9632"/"pvc-vjpqr" Jan 19 00:08:25.518: INFO: Deleting PersistentVolumeClaim "pvc-vjpqr" ... skipping 11 lines ... Jan 19 00:09:05.830: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-vjpqr to be removed Jan 19 00:09:05.858: INFO: Claim "pvc-vjpqr" in namespace "azuredisk-9632" doesn't exist in the system Jan 19 00:09:05.858: INFO: deleting StorageClass azuredisk-9632-disk.csi.azure.com-dynamic-sc-jffnr [1mSTEP:[0m deleting a VolumeSnapshot volume-snapshot-zkn25 [38;5;243m01/19/23 00:09:05.887[0m Jan 19 00:09:05.926: INFO: skip deleting VolumeSnapshotClass azuredisk-9632-disk.csi.azure.com-dynamic-sc-dd9nd Jan 19 00:09:05.926: INFO: Deleting resource group azuredisk-csi-driver-test-515e10b5-978d-11ed-9c8d-ee9a39ac6fd3 {"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-19T00:09:52Z"} ++ early_exit_handler ++ '[' -n 162 ']' ++ kill -TERM 162 ++ cleanup_dind ++ [[ true == \t\r\u\e ]] ++ echo 'Cleaning up after docker' ... skipping 4 lines ...