kubernetes-sigs/azuredisk-csi-driver PR #1665 pull-azuredisk-csi-driver-e2e-capz #1607570868475531264
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | umagnus: cleanup: Use k8s utils pointer instead of Azure autorest/to |
| Result | ABORTED |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 1h8m |
| Revision | 27978f401c8c7a04666cacd92a5a8f685a99c1c3 |
| Refs |
1665 |
... skipping 762 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 135 lines ... # Wait for the kubeconfig to become available. timeout --foreground 300 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets | grep capz-bdakhx-kubeconfig; do sleep 1; done" capz-bdakhx-kubeconfig cluster.x-k8s.io/secret 1 0s # Get kubeconfig and store it locally. /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 get secrets capz-bdakhx-kubeconfig -o json | jq -r .data.value | base64 --decode > ./kubeconfig timeout --foreground 600 bash -c "while ! /home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig get nodes | grep control-plane; do sleep 1; done" error: the server doesn't have a resource type "nodes" capz-bdakhx-control-plane-dc5k7 NotReady control-plane,master 5s v1.23.9 run "/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure/hack/tools/bin/kubectl-v1.22.4 --kubeconfig=./kubeconfig ..." to work with the new target cluster make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/cluster-api-provider-azure' CCM cluster CIDR: 192.168.0.0/16 Waiting for 1 control plane machine(s), 2 worker machine(s), and windows machine(s) to become Ready node/capz-bdakhx-control-plane-dc5k7 condition met ... skipping 40 lines ... 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 11345 100 11345 0 0 77705 0 --:--:-- --:--:-- --:--:-- 77705 Downloading https://get.helm.sh/helm-v3.10.3-linux-amd64.tar.gz Verifying checksum... Done. Preparing to install helm into /usr/local/bin helm installed into /usr/local/bin/helm docker pull capzci.azurecr.io/azuredisk-csi:v1.26.0-b9b2e24baec1ad048551e497ea4e568440e31cad || make container-all push-manifest Error response from daemon: manifest for capzci.azurecr.io/azuredisk-csi:v1.26.0-b9b2e24baec1ad048551e497ea4e568440e31cad not found: manifest unknown: manifest tagged by "v1.26.0-b9b2e24baec1ad048551e497ea4e568440e31cad" is not found make[2]: Entering directory '/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver' CGO_ENABLED=0 GOOS=windows go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=v1.26.0-b9b2e24baec1ad048551e497ea4e568440e31cad -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=b9b2e24baec1ad048551e497ea4e568440e31cad -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2022-12-27T03:10:12Z -extldflags "-static"" -mod vendor -o _output/amd64/azurediskplugin.exe ./pkg/azurediskplugin docker buildx rm container-builder || true ERROR: no builder "container-builder" found docker buildx create --use --name=container-builder container-builder # enable qemu for arm64 build # https://github.com/docker/buildx/issues/464#issuecomment-741507760 docker run --privileged --rm tonistiigi/binfmt --uninstall qemu-aarch64 Unable to find image 'tonistiigi/binfmt:latest' locally ... skipping 1759 lines ... type: string type: object oneOf: - required: ["persistentVolumeClaimName"] - required: ["volumeSnapshotContentName"] volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 60 lines ... type: string volumeSnapshotContentName: description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable. type: string type: object volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 254 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 108 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 865 lines ... image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.6.0" args: - "-csi-address=$(ADDRESS)" - "-v=2" - "-leader-election" - "--leader-election-namespace=kube-system" - '-handle-volume-inuse-error=false' - '-feature-gates=RecoverVolumeExpansionFailure=true' - "-timeout=240s" env: - name: ADDRESS value: /csi/csi.sock volumeMounts: ... skipping 223 lines ... Dec 27 03:24:39.473: INFO: PersistentVolumeClaim pvc-zrjjs found and phase=Bound (6.111849613s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:24:39.473[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:24:39.501[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:24:39.529[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:24:39.53[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:24:39.53[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:24:39.559[0m Dec 27 03:24:39.559: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5t544" in namespace "azuredisk-8081" to be "Succeeded or Failed" Dec 27 03:24:39.604: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 45.18017ms Dec 27 03:24:41.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074183986s Dec 27 03:24:43.632: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 4.073205749s Dec 27 03:24:45.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 6.074033623s Dec 27 03:24:47.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074271406s Dec 27 03:24:49.634: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 10.074900251s Dec 27 03:24:51.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 12.073832385s Dec 27 03:24:53.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 14.073825855s Dec 27 03:24:55.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 16.076330283s Dec 27 03:24:57.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Running", Reason="", readiness=true. Elapsed: 18.075533783s Dec 27 03:24:59.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Running", Reason="", readiness=false. Elapsed: 20.075625901s Dec 27 03:25:01.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.075908133s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:01.635[0m Dec 27 03:25:01.635: INFO: Pod "azuredisk-volume-tester-5t544" satisfied condition "Succeeded or Failed" Dec 27 03:25:01.635: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-5t544" Dec 27 03:25:01.679: INFO: Pod azuredisk-volume-tester-5t544 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5t544 in namespace azuredisk-8081 [38;5;243m12/27/22 03:25:01.679[0m Dec 27 03:25:01.719: INFO: deleting PVC "azuredisk-8081"/"pvc-zrjjs" Dec 27 03:25:01.720: INFO: Deleting PersistentVolumeClaim "pvc-zrjjs" ... skipping 61 lines ... Dec 27 03:24:39.473: INFO: PersistentVolumeClaim pvc-zrjjs found and phase=Bound (6.111849613s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:24:39.473[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:24:39.501[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:24:39.529[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:24:39.53[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:24:39.53[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:24:39.559[0m Dec 27 03:24:39.559: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5t544" in namespace "azuredisk-8081" to be "Succeeded or Failed" Dec 27 03:24:39.604: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 45.18017ms Dec 27 03:24:41.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074183986s Dec 27 03:24:43.632: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 4.073205749s Dec 27 03:24:45.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 6.074033623s Dec 27 03:24:47.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074271406s Dec 27 03:24:49.634: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 10.074900251s Dec 27 03:24:51.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 12.073832385s Dec 27 03:24:53.633: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 14.073825855s Dec 27 03:24:55.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Pending", Reason="", readiness=false. Elapsed: 16.076330283s Dec 27 03:24:57.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Running", Reason="", readiness=true. Elapsed: 18.075533783s Dec 27 03:24:59.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Running", Reason="", readiness=false. Elapsed: 20.075625901s Dec 27 03:25:01.635: INFO: Pod "azuredisk-volume-tester-5t544": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.075908133s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:01.635[0m Dec 27 03:25:01.635: INFO: Pod "azuredisk-volume-tester-5t544" satisfied condition "Succeeded or Failed" Dec 27 03:25:01.635: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-5t544" Dec 27 03:25:01.679: INFO: Pod azuredisk-volume-tester-5t544 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5t544 in namespace azuredisk-8081 [38;5;243m12/27/22 03:25:01.679[0m Dec 27 03:25:01.719: INFO: deleting PVC "azuredisk-8081"/"pvc-zrjjs" Dec 27 03:25:01.720: INFO: Deleting PersistentVolumeClaim "pvc-zrjjs" ... skipping 34 lines ... Dec 27 03:25:29.665: INFO: PersistentVolumeClaim pvc-tlcpk found but phase is Pending instead of Bound. Dec 27 03:25:31.693: INFO: PersistentVolumeClaim pvc-tlcpk found and phase=Bound (4.086286567s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:25:31.693[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:25:31.721[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:25:31.748[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:25:31.748[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m12/27/22 03:25:31.777[0m Dec 27 03:25:31.778: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kj99m" in namespace "azuredisk-2540" to be "Succeeded or Failed" Dec 27 03:25:31.806: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 28.422977ms Dec 27 03:25:33.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057490209s Dec 27 03:25:35.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 4.057789745s Dec 27 03:25:37.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057132315s Dec 27 03:25:39.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 8.057360341s Dec 27 03:25:41.834: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056319912s Dec 27 03:25:43.836: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 12.058152211s Dec 27 03:25:45.836: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Running", Reason="", readiness=false. Elapsed: 14.058819602s Dec 27 03:25:47.837: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.059384729s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:47.837[0m Dec 27 03:25:47.837: INFO: Pod "azuredisk-volume-tester-kj99m" satisfied condition "Succeeded or Failed" Dec 27 03:25:47.837: INFO: deleting Pod "azuredisk-2540"/"azuredisk-volume-tester-kj99m" Dec 27 03:25:47.867: INFO: Pod azuredisk-volume-tester-kj99m has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kj99m in namespace azuredisk-2540 [38;5;243m12/27/22 03:25:47.867[0m Dec 27 03:25:47.904: INFO: deleting PVC "azuredisk-2540"/"pvc-tlcpk" Dec 27 03:25:47.904: INFO: Deleting PersistentVolumeClaim "pvc-tlcpk" ... skipping 38 lines ... Dec 27 03:25:29.665: INFO: PersistentVolumeClaim pvc-tlcpk found but phase is Pending instead of Bound. Dec 27 03:25:31.693: INFO: PersistentVolumeClaim pvc-tlcpk found and phase=Bound (4.086286567s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:25:31.693[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:25:31.721[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:25:31.748[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:25:31.748[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m12/27/22 03:25:31.777[0m Dec 27 03:25:31.778: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-kj99m" in namespace "azuredisk-2540" to be "Succeeded or Failed" Dec 27 03:25:31.806: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 28.422977ms Dec 27 03:25:33.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057490209s Dec 27 03:25:35.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 4.057789745s Dec 27 03:25:37.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057132315s Dec 27 03:25:39.835: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 8.057360341s Dec 27 03:25:41.834: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 10.056319912s Dec 27 03:25:43.836: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Pending", Reason="", readiness=false. Elapsed: 12.058152211s Dec 27 03:25:45.836: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Running", Reason="", readiness=false. Elapsed: 14.058819602s Dec 27 03:25:47.837: INFO: Pod "azuredisk-volume-tester-kj99m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.059384729s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:47.837[0m Dec 27 03:25:47.837: INFO: Pod "azuredisk-volume-tester-kj99m" satisfied condition "Succeeded or Failed" Dec 27 03:25:47.837: INFO: deleting Pod "azuredisk-2540"/"azuredisk-volume-tester-kj99m" Dec 27 03:25:47.867: INFO: Pod azuredisk-volume-tester-kj99m has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-kj99m in namespace azuredisk-2540 [38;5;243m12/27/22 03:25:47.867[0m Dec 27 03:25:47.904: INFO: deleting PVC "azuredisk-2540"/"pvc-tlcpk" Dec 27 03:25:47.904: INFO: Deleting PersistentVolumeClaim "pvc-tlcpk" ... skipping 38 lines ... Dec 27 03:26:32.969: INFO: PersistentVolumeClaim pvc-hdmxf found and phase=Bound (4.087235193s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:26:32.969[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:26:32.997[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:26:33.027[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:26:33.028[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:26:33.028[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:26:33.056[0m Dec 27 03:26:33.056: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7xcdt" in namespace "azuredisk-4728" to be "Succeeded or Failed" Dec 27 03:26:33.084: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 27.774528ms Dec 27 03:26:35.113: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.056890006s Dec 27 03:26:37.114: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058046953s Dec 27 03:26:39.111: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.055342256s Dec 27 03:26:41.113: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.056891323s Dec 27 03:26:43.125: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068820088s ... skipping 12 lines ... Dec 27 03:27:09.112: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 36.055715662s Dec 27 03:27:11.114: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 38.057476752s Dec 27 03:27:13.112: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 40.056258923s Dec 27 03:27:15.115: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 42.058406925s Dec 27 03:27:17.115: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.058905563s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:27:17.115[0m Dec 27 03:27:17.115: INFO: Pod "azuredisk-volume-tester-7xcdt" satisfied condition "Succeeded or Failed" Dec 27 03:27:17.115: INFO: deleting Pod "azuredisk-4728"/"azuredisk-volume-tester-7xcdt" Dec 27 03:27:17.157: INFO: Pod azuredisk-volume-tester-7xcdt has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-7xcdt in namespace azuredisk-4728 [38;5;243m12/27/22 03:27:17.157[0m Dec 27 03:27:17.193: INFO: deleting PVC "azuredisk-4728"/"pvc-hdmxf" Dec 27 03:27:17.193: INFO: Deleting PersistentVolumeClaim "pvc-hdmxf" ... skipping 39 lines ... Dec 27 03:26:32.969: INFO: PersistentVolumeClaim pvc-hdmxf found and phase=Bound (4.087235193s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:26:32.969[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:26:32.997[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:26:33.027[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:26:33.028[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:26:33.028[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:26:33.056[0m Dec 27 03:26:33.056: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7xcdt" in namespace "azuredisk-4728" to be "Succeeded or Failed" Dec 27 03:26:33.084: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 27.774528ms Dec 27 03:26:35.113: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.056890006s Dec 27 03:26:37.114: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.058046953s Dec 27 03:26:39.111: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.055342256s Dec 27 03:26:41.113: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.056891323s Dec 27 03:26:43.125: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068820088s ... skipping 12 lines ... Dec 27 03:27:09.112: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 36.055715662s Dec 27 03:27:11.114: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 38.057476752s Dec 27 03:27:13.112: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 40.056258923s Dec 27 03:27:15.115: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Pending", Reason="", readiness=false. Elapsed: 42.058406925s Dec 27 03:27:17.115: INFO: Pod "azuredisk-volume-tester-7xcdt": Phase="Succeeded", Reason="", readiness=false. Elapsed: 44.058905563s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:27:17.115[0m Dec 27 03:27:17.115: INFO: Pod "azuredisk-volume-tester-7xcdt" satisfied condition "Succeeded or Failed" Dec 27 03:27:17.115: INFO: deleting Pod "azuredisk-4728"/"azuredisk-volume-tester-7xcdt" Dec 27 03:27:17.157: INFO: Pod azuredisk-volume-tester-7xcdt has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-7xcdt in namespace azuredisk-4728 [38;5;243m12/27/22 03:27:17.157[0m Dec 27 03:27:17.193: INFO: deleting PVC "azuredisk-4728"/"pvc-hdmxf" Dec 27 03:27:17.193: INFO: Deleting PersistentVolumeClaim "pvc-hdmxf" ... skipping 40 lines ... [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:28:02.273[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:28:02.3[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:28:02.301[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:28:02.301[0m [1mSTEP:[0m checking that the pod has 'FailedMount' event [38;5;243m12/27/22 03:28:02.329[0m Dec 27 03:28:16.385: INFO: deleting Pod "azuredisk-5466"/"azuredisk-volume-tester-8gccm" Dec 27 03:28:16.469: INFO: Error getting logs for pod azuredisk-volume-tester-8gccm: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-8gccm) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8gccm in namespace azuredisk-5466 [38;5;243m12/27/22 03:28:16.469[0m Dec 27 03:28:16.498: INFO: deleting PVC "azuredisk-5466"/"pvc-pgx87" Dec 27 03:28:16.498: INFO: Deleting PersistentVolumeClaim "pvc-pgx87" [1mSTEP:[0m waiting for claim's PV "pvc-141fc417-6c9a-4c56-9065-95c81d2349ea" to be deleted [38;5;243m12/27/22 03:28:16.527[0m Dec 27 03:28:16.527: INFO: Waiting up to 10m0s for PersistentVolume pvc-141fc417-6c9a-4c56-9065-95c81d2349ea to get deleted Dec 27 03:28:16.554: INFO: PersistentVolume pvc-141fc417-6c9a-4c56-9065-95c81d2349ea found and phase=Bound (27.268349ms) ... skipping 59 lines ... [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:28:02.273[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:28:02.3[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:28:02.301[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:28:02.301[0m [1mSTEP:[0m checking that the pod has 'FailedMount' event [38;5;243m12/27/22 03:28:02.329[0m Dec 27 03:28:16.385: INFO: deleting Pod "azuredisk-5466"/"azuredisk-volume-tester-8gccm" Dec 27 03:28:16.469: INFO: Error getting logs for pod azuredisk-volume-tester-8gccm: the server rejected our request for an unknown reason (get pods azuredisk-volume-tester-8gccm) [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8gccm in namespace azuredisk-5466 [38;5;243m12/27/22 03:28:16.469[0m Dec 27 03:28:16.498: INFO: deleting PVC "azuredisk-5466"/"pvc-pgx87" Dec 27 03:28:16.498: INFO: Deleting PersistentVolumeClaim "pvc-pgx87" [1mSTEP:[0m waiting for claim's PV "pvc-141fc417-6c9a-4c56-9065-95c81d2349ea" to be deleted [38;5;243m12/27/22 03:28:16.527[0m Dec 27 03:28:16.527: INFO: Waiting up to 10m0s for PersistentVolume pvc-141fc417-6c9a-4c56-9065-95c81d2349ea to get deleted Dec 27 03:28:16.554: INFO: PersistentVolume pvc-141fc417-6c9a-4c56-9065-95c81d2349ea found and phase=Bound (27.268349ms) ... skipping 56 lines ... Dec 27 03:30:47.191: INFO: PersistentVolumeClaim pvc-7wljl found and phase=Bound (4.085955182s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:30:47.192[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:30:47.219[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:30:47.246[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:30:47.247[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:30:47.247[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:30:47.276[0m Dec 27 03:30:47.276: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5tzzb" in namespace "azuredisk-2790" to be "Succeeded or Failed" Dec 27 03:30:47.307: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 30.782222ms Dec 27 03:30:49.336: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059948583s Dec 27 03:30:51.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059130612s Dec 27 03:30:53.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058787631s Dec 27 03:30:55.336: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.0598961s Dec 27 03:30:57.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058913216s Dec 27 03:30:59.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 12.058861278s Dec 27 03:31:01.339: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062673884s Dec 27 03:31:03.338: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062179562s Dec 27 03:31:05.338: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.061420991s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:31:05.338[0m Dec 27 03:31:05.338: INFO: Pod "azuredisk-volume-tester-5tzzb" satisfied condition "Succeeded or Failed" Dec 27 03:31:05.338: INFO: deleting Pod "azuredisk-2790"/"azuredisk-volume-tester-5tzzb" Dec 27 03:31:05.382: INFO: Pod azuredisk-volume-tester-5tzzb has the following logs: e2e-test [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5tzzb in namespace azuredisk-2790 [38;5;243m12/27/22 03:31:05.382[0m Dec 27 03:31:05.418: INFO: deleting PVC "azuredisk-2790"/"pvc-7wljl" Dec 27 03:31:05.418: INFO: Deleting PersistentVolumeClaim "pvc-7wljl" ... skipping 39 lines ... Dec 27 03:30:47.191: INFO: PersistentVolumeClaim pvc-7wljl found and phase=Bound (4.085955182s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:30:47.192[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:30:47.219[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:30:47.246[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:30:47.247[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:30:47.247[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:30:47.276[0m Dec 27 03:30:47.276: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-5tzzb" in namespace "azuredisk-2790" to be "Succeeded or Failed" Dec 27 03:30:47.307: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 30.782222ms Dec 27 03:30:49.336: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.059948583s Dec 27 03:30:51.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.059130612s Dec 27 03:30:53.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.058787631s Dec 27 03:30:55.336: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.0598961s Dec 27 03:30:57.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.058913216s Dec 27 03:30:59.335: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 12.058861278s Dec 27 03:31:01.339: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 14.062673884s Dec 27 03:31:03.338: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062179562s Dec 27 03:31:05.338: INFO: Pod "azuredisk-volume-tester-5tzzb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.061420991s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:31:05.338[0m Dec 27 03:31:05.338: INFO: Pod "azuredisk-volume-tester-5tzzb" satisfied condition "Succeeded or Failed" Dec 27 03:31:05.338: INFO: deleting Pod "azuredisk-2790"/"azuredisk-volume-tester-5tzzb" Dec 27 03:31:05.382: INFO: Pod azuredisk-volume-tester-5tzzb has the following logs: e2e-test [1mSTEP:[0m Deleting pod azuredisk-volume-tester-5tzzb in namespace azuredisk-2790 [38;5;243m12/27/22 03:31:05.382[0m Dec 27 03:31:05.418: INFO: deleting PVC "azuredisk-2790"/"pvc-7wljl" Dec 27 03:31:05.418: INFO: Deleting PersistentVolumeClaim "pvc-7wljl" ... skipping 41 lines ... Dec 27 03:31:49.660: INFO: PersistentVolumeClaim pvc-hfp46 found but phase is Pending instead of Bound. Dec 27 03:31:51.688: INFO: PersistentVolumeClaim pvc-hfp46 found and phase=Bound (4.083761333s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:31:51.688[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:31:51.716[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:31:51.743[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:31:51.743[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:31:51.772[0m Dec 27 03:31:51.772: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-zkqwz" in namespace "azuredisk-5356" to be "Succeeded or Failed" Dec 27 03:31:51.800: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 28.058968ms Dec 27 03:31:53.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057260762s Dec 27 03:31:55.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.057483699s Dec 27 03:31:57.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057656668s Dec 27 03:31:59.829: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.056991965s Dec 27 03:32:01.828: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05581705s Dec 27 03:32:03.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 12.057198189s Dec 27 03:32:05.831: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 14.058293062s Dec 27 03:32:07.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 16.05786088s Dec 27 03:32:09.832: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059259155s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:32:09.832[0m Dec 27 03:32:09.832: INFO: Pod "azuredisk-volume-tester-zkqwz" satisfied condition "Succeeded or Failed" Dec 27 03:32:09.832: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-zkqwz" Dec 27 03:32:09.862: INFO: Pod azuredisk-volume-tester-zkqwz has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-zkqwz in namespace azuredisk-5356 [38;5;243m12/27/22 03:32:09.862[0m Dec 27 03:32:09.913: INFO: deleting PVC "azuredisk-5356"/"pvc-hfp46" Dec 27 03:32:09.914: INFO: Deleting PersistentVolumeClaim "pvc-hfp46" ... skipping 43 lines ... Dec 27 03:31:49.660: INFO: PersistentVolumeClaim pvc-hfp46 found but phase is Pending instead of Bound. Dec 27 03:31:51.688: INFO: PersistentVolumeClaim pvc-hfp46 found and phase=Bound (4.083761333s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:31:51.688[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:31:51.716[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:31:51.743[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:31:51.743[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:31:51.772[0m Dec 27 03:31:51.772: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-zkqwz" in namespace "azuredisk-5356" to be "Succeeded or Failed" Dec 27 03:31:51.800: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 28.058968ms Dec 27 03:31:53.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.057260762s Dec 27 03:31:55.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.057483699s Dec 27 03:31:57.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.057656668s Dec 27 03:31:59.829: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.056991965s Dec 27 03:32:01.828: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05581705s Dec 27 03:32:03.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 12.057198189s Dec 27 03:32:05.831: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 14.058293062s Dec 27 03:32:07.830: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Pending", Reason="", readiness=false. Elapsed: 16.05786088s Dec 27 03:32:09.832: INFO: Pod "azuredisk-volume-tester-zkqwz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.059259155s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:32:09.832[0m Dec 27 03:32:09.832: INFO: Pod "azuredisk-volume-tester-zkqwz" satisfied condition "Succeeded or Failed" Dec 27 03:32:09.832: INFO: deleting Pod "azuredisk-5356"/"azuredisk-volume-tester-zkqwz" Dec 27 03:32:09.862: INFO: Pod azuredisk-volume-tester-zkqwz has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-zkqwz in namespace azuredisk-5356 [38;5;243m12/27/22 03:32:09.862[0m Dec 27 03:32:09.913: INFO: deleting PVC "azuredisk-5356"/"pvc-hfp46" Dec 27 03:32:09.914: INFO: Deleting PersistentVolumeClaim "pvc-hfp46" ... skipping 56 lines ... Dec 27 03:34:14.284: INFO: PersistentVolumeClaim pvc-2c2ng found but phase is Pending instead of Bound. Dec 27 03:34:16.313: INFO: PersistentVolumeClaim pvc-2c2ng found and phase=Bound (4.085072811s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:34:16.313[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:34:16.34[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:34:16.368[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:34:16.368[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:34:16.398[0m Dec 27 03:34:16.398: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-57wgp" in namespace "azuredisk-5194" to be "Succeeded or Failed" Dec 27 03:34:16.425: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 26.899813ms Dec 27 03:34:18.454: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055879437s Dec 27 03:34:20.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.055138696s Dec 27 03:34:22.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.055421864s Dec 27 03:34:24.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.055521756s Dec 27 03:34:26.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05509522s ... skipping 4 lines ... Dec 27 03:34:36.454: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 20.056636961s Dec 27 03:34:38.457: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 22.059246733s Dec 27 03:34:40.457: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 24.058866773s Dec 27 03:34:42.455: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 26.057099415s Dec 27 03:34:44.455: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Succeeded", Reason="", readiness=false. Elapsed: 28.057222511s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:34:44.455[0m Dec 27 03:34:44.455: INFO: Pod "azuredisk-volume-tester-57wgp" satisfied condition "Succeeded or Failed" Dec 27 03:34:44.455: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-57wgp" Dec 27 03:34:44.493: INFO: Pod azuredisk-volume-tester-57wgp has the following logs: hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-57wgp in namespace azuredisk-5194 [38;5;243m12/27/22 03:34:44.493[0m Dec 27 03:34:44.546: INFO: deleting PVC "azuredisk-5194"/"pvc-2c2ng" ... skipping 75 lines ... Dec 27 03:34:14.284: INFO: PersistentVolumeClaim pvc-2c2ng found but phase is Pending instead of Bound. Dec 27 03:34:16.313: INFO: PersistentVolumeClaim pvc-2c2ng found and phase=Bound (4.085072811s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:34:16.313[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:34:16.34[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:34:16.368[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:34:16.368[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:34:16.398[0m Dec 27 03:34:16.398: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-57wgp" in namespace "azuredisk-5194" to be "Succeeded or Failed" Dec 27 03:34:16.425: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 26.899813ms Dec 27 03:34:18.454: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055879437s Dec 27 03:34:20.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.055138696s Dec 27 03:34:22.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.055421864s Dec 27 03:34:24.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.055521756s Dec 27 03:34:26.453: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.05509522s ... skipping 4 lines ... Dec 27 03:34:36.454: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 20.056636961s Dec 27 03:34:38.457: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 22.059246733s Dec 27 03:34:40.457: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 24.058866773s Dec 27 03:34:42.455: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Pending", Reason="", readiness=false. Elapsed: 26.057099415s Dec 27 03:34:44.455: INFO: Pod "azuredisk-volume-tester-57wgp": Phase="Succeeded", Reason="", readiness=false. Elapsed: 28.057222511s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:34:44.455[0m Dec 27 03:34:44.455: INFO: Pod "azuredisk-volume-tester-57wgp" satisfied condition "Succeeded or Failed" Dec 27 03:34:44.455: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-57wgp" Dec 27 03:34:44.493: INFO: Pod azuredisk-volume-tester-57wgp has the following logs: hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-57wgp in namespace azuredisk-5194 [38;5;243m12/27/22 03:34:44.493[0m Dec 27 03:34:44.546: INFO: deleting PVC "azuredisk-5194"/"pvc-2c2ng" ... skipping 57 lines ... Dec 27 03:37:42.460: INFO: PersistentVolumeClaim pvc-qr6cs found and phase=Bound (4.083764925s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:37:42.46[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:37:42.487[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:37:42.544[0m Dec 27 03:37:42.544: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7dctf" in namespace "azuredisk-1353" to be "Error status code" Dec 27 03:37:42.577: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 33.220253ms Dec 27 03:37:44.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.061679907s Dec 27 03:37:46.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.06177058s Dec 27 03:37:48.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06093342s Dec 27 03:37:50.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061350655s Dec 27 03:37:52.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.061535204s Dec 27 03:37:54.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 12.061172127s Dec 27 03:37:56.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 14.061829826s Dec 27 03:37:58.607: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062547572s Dec 27 03:38:00.607: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Failed", Reason="", readiness=false. Elapsed: 18.062477003s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:38:00.607[0m Dec 27 03:38:00.607: INFO: Pod "azuredisk-volume-tester-7dctf" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:38:00.607[0m Dec 27 03:38:00.648: INFO: deleting Pod "azuredisk-1353"/"azuredisk-volume-tester-7dctf" Dec 27 03:38:00.677: INFO: Pod azuredisk-volume-tester-7dctf has the following logs: touch: /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-7dctf in namespace azuredisk-1353 [38;5;243m12/27/22 03:38:00.677[0m Dec 27 03:38:00.744: INFO: deleting PVC "azuredisk-1353"/"pvc-qr6cs" ... skipping 39 lines ... Dec 27 03:37:42.460: INFO: PersistentVolumeClaim pvc-qr6cs found and phase=Bound (4.083764925s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:37:42.46[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:37:42.487[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:37:42.514[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:37:42.544[0m Dec 27 03:37:42.544: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-7dctf" in namespace "azuredisk-1353" to be "Error status code" Dec 27 03:37:42.577: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 33.220253ms Dec 27 03:37:44.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.061679907s Dec 27 03:37:46.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.06177058s Dec 27 03:37:48.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06093342s Dec 27 03:37:50.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061350655s Dec 27 03:37:52.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.061535204s Dec 27 03:37:54.605: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 12.061172127s Dec 27 03:37:56.606: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 14.061829826s Dec 27 03:37:58.607: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062547572s Dec 27 03:38:00.607: INFO: Pod "azuredisk-volume-tester-7dctf": Phase="Failed", Reason="", readiness=false. Elapsed: 18.062477003s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:38:00.607[0m Dec 27 03:38:00.607: INFO: Pod "azuredisk-volume-tester-7dctf" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:38:00.607[0m Dec 27 03:38:00.648: INFO: deleting Pod "azuredisk-1353"/"azuredisk-volume-tester-7dctf" Dec 27 03:38:00.677: INFO: Pod azuredisk-volume-tester-7dctf has the following logs: touch: /mnt/test-1/data: Read-only file system [1mSTEP:[0m Deleting pod azuredisk-volume-tester-7dctf in namespace azuredisk-1353 [38;5;243m12/27/22 03:38:00.677[0m Dec 27 03:38:00.744: INFO: deleting PVC "azuredisk-1353"/"pvc-qr6cs" ... skipping 720 lines ... Dec 27 03:46:10.177: INFO: PersistentVolumeClaim pvc-tbsrb found and phase=Bound (4.084098495s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:46:10.177[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:46:10.205[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:46:10.232[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:46:10.233[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:46:10.233[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:46:10.262[0m Dec 27 03:46:10.263: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-2cnnq" in namespace "azuredisk-59" to be "Succeeded or Failed" Dec 27 03:46:10.298: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 34.859961ms Dec 27 03:46:12.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063432561s Dec 27 03:46:14.327: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.063918859s Dec 27 03:46:16.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062918971s Dec 27 03:46:18.332: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.069627567s Dec 27 03:46:20.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063732264s ... skipping 2 lines ... Dec 27 03:46:26.325: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062827344s Dec 27 03:46:28.325: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 18.062769995s Dec 27 03:46:30.329: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 20.066200711s Dec 27 03:46:32.327: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 22.064158297s Dec 27 03:46:34.329: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.065924472s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:46:34.329[0m Dec 27 03:46:34.329: INFO: Pod "azuredisk-volume-tester-2cnnq" satisfied condition "Succeeded or Failed" [1mSTEP:[0m sleep 5s and then clone volume [38;5;243m12/27/22 03:46:34.329[0m [1mSTEP:[0m cloning existing volume [38;5;243m12/27/22 03:46:39.332[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m12/27/22 03:46:39.388[0m [1mSTEP:[0m creating a PVC [38;5;243m12/27/22 03:46:39.388[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m12/27/22 03:46:39.42[0m Dec 27 03:46:39.420: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-gpbs4] to have phase Bound ... skipping 2 lines ... Dec 27 03:46:43.508: INFO: PersistentVolumeClaim pvc-gpbs4 found and phase=Bound (4.088114404s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:46:43.508[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:46:43.536[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:46:43.594[0m Dec 27 03:46:43.594: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-452qn" in namespace "azuredisk-59" to be "Succeeded or Failed" Dec 27 03:46:43.621: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 26.901628ms Dec 27 03:46:45.650: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055616039s Dec 27 03:46:47.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.054891665s Dec 27 03:46:49.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.054644012s Dec 27 03:46:51.655: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061080373s Dec 27 03:46:53.652: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057619426s ... skipping 3 lines ... Dec 27 03:47:01.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 18.057084572s Dec 27 03:47:03.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 20.055035991s Dec 27 03:47:05.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 22.057021389s Dec 27 03:47:07.650: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 24.056291368s Dec 27 03:47:09.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.056614319s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:47:09.651[0m Dec 27 03:47:09.651: INFO: Pod "azuredisk-volume-tester-452qn" satisfied condition "Succeeded or Failed" Dec 27 03:47:09.651: INFO: deleting Pod "azuredisk-59"/"azuredisk-volume-tester-452qn" Dec 27 03:47:09.689: INFO: Pod azuredisk-volume-tester-452qn has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-452qn in namespace azuredisk-59 [38;5;243m12/27/22 03:47:09.689[0m Dec 27 03:47:09.730: INFO: deleting PVC "azuredisk-59"/"pvc-gpbs4" Dec 27 03:47:09.730: INFO: Deleting PersistentVolumeClaim "pvc-gpbs4" ... skipping 51 lines ... Dec 27 03:46:10.177: INFO: PersistentVolumeClaim pvc-tbsrb found and phase=Bound (4.084098495s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:46:10.177[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:46:10.205[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:46:10.232[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:46:10.233[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:46:10.233[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:46:10.262[0m Dec 27 03:46:10.263: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-2cnnq" in namespace "azuredisk-59" to be "Succeeded or Failed" Dec 27 03:46:10.298: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 34.859961ms Dec 27 03:46:12.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.063432561s Dec 27 03:46:14.327: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.063918859s Dec 27 03:46:16.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.062918971s Dec 27 03:46:18.332: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.069627567s Dec 27 03:46:20.326: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063732264s ... skipping 2 lines ... Dec 27 03:46:26.325: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 16.062827344s Dec 27 03:46:28.325: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 18.062769995s Dec 27 03:46:30.329: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 20.066200711s Dec 27 03:46:32.327: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Pending", Reason="", readiness=false. Elapsed: 22.064158297s Dec 27 03:46:34.329: INFO: Pod "azuredisk-volume-tester-2cnnq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.065924472s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:46:34.329[0m Dec 27 03:46:34.329: INFO: Pod "azuredisk-volume-tester-2cnnq" satisfied condition "Succeeded or Failed" [1mSTEP:[0m sleep 5s and then clone volume [38;5;243m12/27/22 03:46:34.329[0m [1mSTEP:[0m cloning existing volume [38;5;243m12/27/22 03:46:39.332[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m12/27/22 03:46:39.388[0m [1mSTEP:[0m creating a PVC [38;5;243m12/27/22 03:46:39.388[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m12/27/22 03:46:39.42[0m Dec 27 03:46:39.420: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-gpbs4] to have phase Bound ... skipping 2 lines ... Dec 27 03:46:43.508: INFO: PersistentVolumeClaim pvc-gpbs4 found and phase=Bound (4.088114404s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:46:43.508[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:46:43.536[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m12/27/22 03:46:43.564[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:46:43.594[0m Dec 27 03:46:43.594: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-452qn" in namespace "azuredisk-59" to be "Succeeded or Failed" Dec 27 03:46:43.621: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 26.901628ms Dec 27 03:46:45.650: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.055616039s Dec 27 03:46:47.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.054891665s Dec 27 03:46:49.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.054644012s Dec 27 03:46:51.655: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061080373s Dec 27 03:46:53.652: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.057619426s ... skipping 3 lines ... Dec 27 03:47:01.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 18.057084572s Dec 27 03:47:03.649: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 20.055035991s Dec 27 03:47:05.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 22.057021389s Dec 27 03:47:07.650: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Pending", Reason="", readiness=false. Elapsed: 24.056291368s Dec 27 03:47:09.651: INFO: Pod "azuredisk-volume-tester-452qn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 26.056614319s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:47:09.651[0m Dec 27 03:47:09.651: INFO: Pod "azuredisk-volume-tester-452qn" satisfied condition "Succeeded or Failed" Dec 27 03:47:09.651: INFO: deleting Pod "azuredisk-59"/"azuredisk-volume-tester-452qn" Dec 27 03:47:09.689: INFO: Pod azuredisk-volume-tester-452qn has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-452qn in namespace azuredisk-59 [38;5;243m12/27/22 03:47:09.689[0m Dec 27 03:47:09.730: INFO: deleting PVC "azuredisk-59"/"pvc-gpbs4" Dec 27 03:47:09.730: INFO: Deleting PersistentVolumeClaim "pvc-gpbs4" ... skipping 50 lines ... Dec 27 03:48:05.032: INFO: PersistentVolumeClaim pvc-pkggd found and phase=Bound (4.084996634s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:48:05.032[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:48:05.06[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:48:05.087[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:48:05.087[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:48:05.088[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:48:05.116[0m Dec 27 03:48:05.117: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-524hs" in namespace "azuredisk-2546" to be "Succeeded or Failed" Dec 27 03:48:05.149: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 32.503637ms Dec 27 03:48:07.178: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.061486715s Dec 27 03:48:09.179: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 4.062252078s Dec 27 03:48:11.178: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 6.061396905s Dec 27 03:48:13.177: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 8.060528961s Dec 27 03:48:15.178: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 10.061416286s Dec 27 03:48:17.178: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 12.061439011s Dec 27 03:48:19.178: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 14.061389198s Dec 27 03:48:21.180: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Pending", Reason="", readiness=false. Elapsed: 16.063201462s Dec 27 03:48:23.181: INFO: Pod "azuredisk-volume-tester-524hs": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.064501201s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:48:23.181[0m Dec 27 03:48:23.181: INFO: Pod "azuredisk-volume-tester-524hs" satisfied condition "Succeeded or Failed" [1mSTEP:[0m sleep 5s and then clone volume [38;5;243m12/27/22 03:48:23.181[0m [1mSTEP:[0m cloning existing volume [38;5;243m12/27/22 03:48:28.182[0m [1mSTEP:[0m setting up the PVC and PV [38;5;243m12/27/22 03:48:28.238[0m [1mSTEP:[0m creating a PVC [38;5;243m12/27/22 03:48:28.238[0m [1mSTEP:[0m waiting for PVC to be in phase "Bound" [38;5;243m12/27/22 03:48:28.267[0m Dec 27 03:48:28.267: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-xvhrj] to have phase Bound ... skipping 2 lines ... Dec 27 03:48:32.353: INFO: PersistentVolumeClaim pvc-xvhrj found and phase=Bound (4.085550291s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:48:32.353[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:48:32.38[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:48:32.407[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:48:32.407[0m [1mSTEP:[0m deploying a second pod with cloned volume [38;5;243m12/27/22 03:48:32.407[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:48:32.438[0m Dec 27 03:48:32.438: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-lzhp6" in namespace "azuredisk-2546" to be "Succeeded or Failed" Dec 27 03:48:32.471: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 32.971117ms Dec 27 03:48:34.499: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.061109262s Dec 27 03:48:36.501: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.062814641s Dec 27 03:48:38.500: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.06197435s Dec 27 03:48:40.499: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.061192638s Dec 27 03:48:42.501: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.063732028s ... skipping 4 lines ... Dec 27 03:48:52.500: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 20.061962067s Dec 27 03:48:54.499: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 22.061256077s Dec 27 03:48:56.499: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Pending", Reason="", readiness=false. Elapsed: 24.061437025s Dec 27 03:48:58.500: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Running", Reason="", readiness=false. Elapsed: 26.06255117s Dec 27 03:49:00.500: INFO: Pod "azuredisk-volume-tester-lzhp6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 28.062414363s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:49:00.5[0m Dec 27 03:49:00.500: INFO: Pod "azuredisk-volume-tester-lzhp6" satisfied condition "Succeeded or Failed" Dec 27 03:49:00.500: INFO: deleting Pod "azuredisk-2546"/"azuredisk-volume-tester-lzhp6" Dec 27 03:49:00.530: INFO: Pod azuredisk-volume-tester-lzhp6 has the following logs: 20.0G [1mSTEP:[0m Deleting pod azuredisk-volume-tester-lzhp6 in namespace azuredisk-2546 [38;5;243m12/27/22 03:49:00.53[0m Dec 27 03:49:00.564: INFO: deleting PVC "azuredisk-2546"/"pvc-xvhrj" Dec 27 03:49:00.564: INFO: Deleting PersistentVolumeClaim "pvc-xvhrj" ... skipping 22 lines ...