kubernetes-sigs/azuredisk-csi-driver PR #1665 pull-azuredisk-csi-driver-e2e-windows-containerd #1607570866793615360
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 | 1h6m |
| Revision | 27978f401c8c7a04666cacd92a5a8f685a99c1c3 |
| Refs |
1665 |
... skipping 107 lines ... 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 11345 100 11345 0 0 149k 0 --:--:-- --:--:-- --:--:-- 151k 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 k8sprow.azurecr.io/azuredisk-csi:v1.26.0-b9b2e24baec1ad048551e497ea4e568440e31cad || make container-all push-manifest Error response from daemon: manifest for k8sprow.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:05:11Z -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 1783 lines ... type: string type: object oneOf: - required: ["persistentVolumeClaimName"] - required: ["volumeSnapshotContentName"] volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 60 lines ... type: string volumeSnapshotContentName: description: volumeSnapshotContentName specifies the name of a pre-existing VolumeSnapshotContent object representing an existing volume snapshot. This field should be set if the snapshot already exists and only needs a representation in Kubernetes. This field is immutable. type: string type: object volumeSnapshotClassName: description: 'VolumeSnapshotClassName is the name of the VolumeSnapshotClass requested by the VolumeSnapshot. VolumeSnapshotClassName may be left nil to indicate that the default SnapshotClass should be used. A given cluster may have multiple default Volume SnapshotClasses: one default per CSI Driver. If a VolumeSnapshot does not specify a SnapshotClass, VolumeSnapshotSource will be checked to figure out what the associated CSI Driver is, and the default VolumeSnapshotClass associated with that CSI Driver will be used. If more than one VolumeSnapshotClass exist for a given CSI Driver and more than one have been marked as default, CreateSnapshot will fail and generate an event. Empty string is not allowed for this field.' type: string required: - source type: object status: description: status represents the current information of a snapshot. Consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object. ... skipping 2 lines ... description: 'boundVolumeSnapshotContentName is the name of the VolumeSnapshotContent object to which this VolumeSnapshot object intends to bind to. If not specified, it indicates that the VolumeSnapshot object has not been successfully bound to a VolumeSnapshotContent object yet. NOTE: To avoid possible security issues, consumers must verify binding between VolumeSnapshot and VolumeSnapshotContent objects is successful (by validating that both VolumeSnapshot and VolumeSnapshotContent point at each other) before using this object.' type: string creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it may indicate that the creation time of the snapshot is unknown. format: date-time type: string error: description: error is the last observed error during snapshot creation, if any. This field could be helpful to upper level controllers(i.e., application controller) to decide whether they should continue on waiting for the snapshot to be created based on the type of error reported. The snapshot controller will keep retrying when an error occurrs during the snapshot creation. Upon success, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if the snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: type: string description: restoreSize represents the minimum size of volume required to create a volume from this snapshot. In dynamic snapshot creation case, this field will be filled in by the snapshot controller with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. pattern: ^(\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))(([KMGTPE]i)|[numkMGTPE]|([eE](\+|-)?(([0-9]+(\.[0-9]*)?)|(\.[0-9]+))))?$ x-kubernetes-int-or-string: true type: object required: - spec type: object ... skipping 254 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 108 lines ... description: status represents the current information of a snapshot. properties: creationTime: description: creationTime is the timestamp when the point-in-time snapshot is taken by the underlying storage system. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "creation_time" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "creation_time" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. If not specified, it indicates the creation time is unknown. The format of this field is a Unix nanoseconds time encoded as an int64. On Unix, the command `date +%s%N` returns the current time in nanoseconds since 1970-01-01 00:00:00 UTC. format: int64 type: integer error: description: error is the last observed error during snapshot creation, if any. Upon success after retry, this error field will be cleared. properties: message: description: 'message is a string detailing the encountered error during snapshot creation if specified. NOTE: message may be logged, and it should not contain sensitive information.' type: string time: description: time is the timestamp when the error was encountered. format: date-time type: string type: object readyToUse: description: readyToUse indicates if a snapshot is ready to be used to restore a volume. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "ready_to_use" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "ready_to_use" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it, otherwise, this field will be set to "True". If not specified, it means the readiness of a snapshot is unknown. type: boolean restoreSize: description: restoreSize represents the complete size of the snapshot in bytes. In dynamic snapshot creation case, this field will be filled in by the CSI snapshotter sidecar with the "size_bytes" value returned from CSI "CreateSnapshot" gRPC call. For a pre-existing snapshot, this field will be filled with the "size_bytes" value returned from the CSI "ListSnapshots" gRPC call if the driver supports it. When restoring a volume from this snapshot, the size of the volume MUST NOT be smaller than the restoreSize if it is specified, otherwise the restoration will fail. If not specified, it indicates that the size is unknown. format: int64 minimum: 0 type: integer snapshotHandle: description: snapshotHandle is the CSI "snapshot_id" of a snapshot on the underlying storage system. If not specified, it indicates that dynamic snapshot creation has either failed or it is still in progress. type: string type: object required: - spec type: object served: true ... skipping 673 lines ... image: "mcr.microsoft.com/oss/kubernetes-csi/csi-resizer:v1.6.0" args: - "-csi-address=$(ADDRESS)" - "-v=2" - "-leader-election" - "--leader-election-namespace=kube-system" - '-handle-volume-inuse-error=false' - '-feature-gates=RecoverVolumeExpansionFailure=true' - "-timeout=240s" env: - name: ADDRESS value: /csi/csi.sock volumeMounts: ... skipping 217 lines ... Dec 27 03:16:16.634: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rlpxr] to have phase Bound Dec 27 03:16:16.673: INFO: PersistentVolumeClaim pvc-rlpxr found and phase=Bound (39.386625ms) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:16:16.673[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:16:16.707[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:16:16.741[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:16:16.741[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:16:16.778[0m Dec 27 03:16:16.778: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-p5cs9" in namespace "azuredisk-8081" to be "Error status code" Dec 27 03:16:16.814: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 36.353426ms Dec 27 03:16:18.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071686466s Dec 27 03:16:20.858: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.079988642s Dec 27 03:16:22.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.07099213s Dec 27 03:16:24.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.070789897s Dec 27 03:16:26.848: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.070733056s ... skipping 25 lines ... Dec 27 03:17:18.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m2.071213733s Dec 27 03:17:20.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m4.071681108s Dec 27 03:17:22.851: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m6.073413266s Dec 27 03:17:24.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m8.071632048s Dec 27 03:17:26.851: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.073451359s Dec 27 03:17:28.850: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=false. Elapsed: 1m12.072002333s Dec 27 03:17:30.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Failed", Reason="", readiness=false. Elapsed: 1m14.071680113s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:17:30.85[0m Dec 27 03:17:30.850: INFO: Pod "azuredisk-volume-tester-p5cs9" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:17:30.85[0m Dec 27 03:17:30.924: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-p5cs9" Dec 27 03:17:30.966: INFO: Pod azuredisk-volume-tester-p5cs9 has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied. At line:1 char:22 + ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ... + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ... skipping 80 lines ... Dec 27 03:16:16.634: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-rlpxr] to have phase Bound Dec 27 03:16:16.673: INFO: PersistentVolumeClaim pvc-rlpxr found and phase=Bound (39.386625ms) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:16:16.673[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:16:16.707[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:16:16.741[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:16:16.741[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:16:16.778[0m Dec 27 03:16:16.778: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-p5cs9" in namespace "azuredisk-8081" to be "Error status code" Dec 27 03:16:16.814: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 36.353426ms Dec 27 03:16:18.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071686466s Dec 27 03:16:20.858: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.079988642s Dec 27 03:16:22.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.07099213s Dec 27 03:16:24.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.070789897s Dec 27 03:16:26.848: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.070733056s ... skipping 25 lines ... Dec 27 03:17:18.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m2.071213733s Dec 27 03:17:20.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m4.071681108s Dec 27 03:17:22.851: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m6.073413266s Dec 27 03:17:24.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=true. Elapsed: 1m8.071632048s Dec 27 03:17:26.851: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.073451359s Dec 27 03:17:28.850: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Running", Reason="", readiness=false. Elapsed: 1m12.072002333s Dec 27 03:17:30.849: INFO: Pod "azuredisk-volume-tester-p5cs9": Phase="Failed", Reason="", readiness=false. Elapsed: 1m14.071680113s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:17:30.85[0m Dec 27 03:17:30.850: INFO: Pod "azuredisk-volume-tester-p5cs9" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:17:30.85[0m Dec 27 03:17:30.924: INFO: deleting Pod "azuredisk-8081"/"azuredisk-volume-tester-p5cs9" Dec 27 03:17:30.966: INFO: Pod azuredisk-volume-tester-p5cs9 has the following logs: Out-File : Access to the path 'C:\mnt\test-1\data.txt' is denied. At line:1 char:22 + ... cho 'hello world' | Out-File -FilePath C:\mnt\test-1\data.txt; Get-Co ... + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ... skipping 138 lines ... [1mSTEP:[0m Successfully provisioned a shared disk volume: "/subscriptions/0e46bd28-a80f-4d3a-8200-d9eb8d80cb2e/resourceGroups/kubetest-mwpb3kdi/providers/Microsoft.Compute/disks/single-shared-disk" [38;5;243m12/27/22 03:18:15.393[0m [1mSTEP:[0m Destroying namespace "azuredisk-4728" for this suite. [38;5;243m12/27/22 03:18:16.064[0m [38;5;243m<< End Captured GinkgoWriter Output[0m [38;5;243m------------------------------[0m [0mPre-Provisioned [38;5;243m[single-az][0m [1mshould fail when maxShares is invalid [disk.csi.azure.com][windows][0m [38;5;243m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:166[0m [1mSTEP:[0m Creating a kubernetes client [38;5;243m12/27/22 03:18:16.1[0m Dec 27 03:18:16.101: INFO: >>> kubeConfig: /root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json [1mSTEP:[0m Building a namespace api object, basename azuredisk [38;5;243m12/27/22 03:18:16.102[0m [1mSTEP:[0m Waiting for a default service account to be provisioned in namespace [38;5;243m12/27/22 03:18:16.209[0m [1mSTEP:[0m Waiting for kube-root-ca.crt to be provisioned in namespace [38;5;243m12/27/22 03:18:16.274[0m ... skipping 2 lines ... [38;5;243m------------------------------[0m [38;5;10m• [0.275 seconds][0m Pre-Provisioned [38;5;243m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:38[0m [single-az] [38;5;243m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:71[0m should fail when maxShares is invalid [disk.csi.azure.com][windows] [38;5;243m/home/prow/go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning_test.go:166[0m [38;5;243mBegin Captured GinkgoWriter Output >>[0m [1mSTEP:[0m Creating a kubernetes client [38;5;243m12/27/22 03:18:16.1[0m Dec 27 03:18:16.101: INFO: >>> kubeConfig: /root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json [1mSTEP:[0m Building a namespace api object, basename azuredisk [38;5;243m12/27/22 03:18:16.102[0m ... skipping 88 lines ... Dec 27 03:18:23.992: INFO: PersistentVolumeClaim pvc-dfpgf found and phase=Bound (37.148696ms) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:18:23.992[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:18:24.027[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:18:24.063[0m [1mSTEP:[0m attaching disk to node#0 [38;5;243m12/27/22 03:18:24.13[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:18:40.949[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:18:40.994[0m Dec 27 03:18:40.994: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-p9tmb" in namespace "azuredisk-5194" to be "Succeeded or Failed" Dec 27 03:18:41.028: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.432179ms Dec 27 03:18:43.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.06879943s Dec 27 03:18:45.064: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.070025488s Dec 27 03:18:47.067: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.072466127s Dec 27 03:18:49.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.068426192s Dec 27 03:18:51.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068371221s ... skipping 27 lines ... Dec 27 03:19:47.070: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=true. Elapsed: 1m6.076034094s Dec 27 03:19:49.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=true. Elapsed: 1m8.068644498s Dec 27 03:19:51.064: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.069524078s Dec 27 03:19:53.065: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=false. Elapsed: 1m12.070167614s Dec 27 03:19:55.075: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m14.080614789s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:19:55.075[0m Dec 27 03:19:55.076: INFO: Pod "azuredisk-volume-tester-p9tmb" satisfied condition "Succeeded or Failed" Dec 27 03:19:55.076: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-p9tmb" Dec 27 03:19:55.138: INFO: Pod azuredisk-volume-tester-p9tmb has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-p9tmb in namespace azuredisk-5194 [38;5;243m12/27/22 03:19:55.138[0m Dec 27 03:19:55.265: INFO: deleting PVC "azuredisk-5194"/"pvc-dfpgf" Dec 27 03:19:55.266: INFO: Deleting PersistentVolumeClaim "pvc-dfpgf" ... skipping 37 lines ... Dec 27 03:18:23.992: INFO: PersistentVolumeClaim pvc-dfpgf found and phase=Bound (37.148696ms) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:18:23.992[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:18:24.027[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:18:24.063[0m [1mSTEP:[0m attaching disk to node#0 [38;5;243m12/27/22 03:18:24.13[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:18:40.949[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:18:40.994[0m Dec 27 03:18:40.994: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-p9tmb" in namespace "azuredisk-5194" to be "Succeeded or Failed" Dec 27 03:18:41.028: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 33.432179ms Dec 27 03:18:43.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.06879943s Dec 27 03:18:45.064: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.070025488s Dec 27 03:18:47.067: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.072466127s Dec 27 03:18:49.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.068426192s Dec 27 03:18:51.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068371221s ... skipping 27 lines ... Dec 27 03:19:47.070: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=true. Elapsed: 1m6.076034094s Dec 27 03:19:49.063: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=true. Elapsed: 1m8.068644498s Dec 27 03:19:51.064: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.069524078s Dec 27 03:19:53.065: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Running", Reason="", readiness=false. Elapsed: 1m12.070167614s Dec 27 03:19:55.075: INFO: Pod "azuredisk-volume-tester-p9tmb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m14.080614789s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:19:55.075[0m Dec 27 03:19:55.076: INFO: Pod "azuredisk-volume-tester-p9tmb" satisfied condition "Succeeded or Failed" Dec 27 03:19:55.076: INFO: deleting Pod "azuredisk-5194"/"azuredisk-volume-tester-p9tmb" Dec 27 03:19:55.138: INFO: Pod azuredisk-volume-tester-p9tmb has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-p9tmb in namespace azuredisk-5194 [38;5;243m12/27/22 03:19:55.138[0m Dec 27 03:19:55.265: INFO: deleting PVC "azuredisk-5194"/"pvc-dfpgf" Dec 27 03:19:55.266: INFO: Deleting PersistentVolumeClaim "pvc-dfpgf" ... skipping 68 lines ... Dec 27 03:20:32.975: INFO: PersistentVolumeClaim pvc-tbvb6 found and phase=Bound (4.116500494s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:20:32.975[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:20:33.01[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:20:33.044[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:20:33.044[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:20:33.045[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:20:33.082[0m Dec 27 03:20:33.083: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-8ghc5" in namespace "azuredisk-2888" to be "Succeeded or Failed" Dec 27 03:20:33.137: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 53.812644ms Dec 27 03:20:35.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.090496882s Dec 27 03:20:37.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.09030638s Dec 27 03:20:39.175: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.091366182s Dec 27 03:20:41.173: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089533705s Dec 27 03:20:43.175: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.091341679s ... skipping 15 lines ... Dec 27 03:21:15.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=true. Elapsed: 42.092900935s Dec 27 03:21:17.180: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=true. Elapsed: 44.096849544s Dec 27 03:21:19.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=false. Elapsed: 46.092945175s Dec 27 03:21:21.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=false. Elapsed: 48.093058472s Dec 27 03:21:23.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.090509958s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:21:23.174[0m Dec 27 03:21:23.174: INFO: Pod "azuredisk-volume-tester-8ghc5" satisfied condition "Succeeded or Failed" Dec 27 03:21:23.174: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-8ghc5" Dec 27 03:21:23.214: INFO: Pod azuredisk-volume-tester-8ghc5 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8ghc5 in namespace azuredisk-2888 [38;5;243m12/27/22 03:21:23.214[0m Dec 27 03:21:23.281: INFO: deleting PVC "azuredisk-2888"/"pvc-tbvb6" Dec 27 03:21:23.281: INFO: Deleting PersistentVolumeClaim "pvc-tbvb6" ... skipping 39 lines ... Dec 27 03:20:32.975: INFO: PersistentVolumeClaim pvc-tbvb6 found and phase=Bound (4.116500494s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:20:32.975[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:20:33.01[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:20:33.044[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:20:33.044[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:20:33.045[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:20:33.082[0m Dec 27 03:20:33.083: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-8ghc5" in namespace "azuredisk-2888" to be "Succeeded or Failed" Dec 27 03:20:33.137: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 53.812644ms Dec 27 03:20:35.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.090496882s Dec 27 03:20:37.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.09030638s Dec 27 03:20:39.175: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.091366182s Dec 27 03:20:41.173: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.089533705s Dec 27 03:20:43.175: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.091341679s ... skipping 15 lines ... Dec 27 03:21:15.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=true. Elapsed: 42.092900935s Dec 27 03:21:17.180: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=true. Elapsed: 44.096849544s Dec 27 03:21:19.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=false. Elapsed: 46.092945175s Dec 27 03:21:21.176: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Running", Reason="", readiness=false. Elapsed: 48.093058472s Dec 27 03:21:23.174: INFO: Pod "azuredisk-volume-tester-8ghc5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.090509958s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:21:23.174[0m Dec 27 03:21:23.174: INFO: Pod "azuredisk-volume-tester-8ghc5" satisfied condition "Succeeded or Failed" Dec 27 03:21:23.174: INFO: deleting Pod "azuredisk-2888"/"azuredisk-volume-tester-8ghc5" Dec 27 03:21:23.214: INFO: Pod azuredisk-volume-tester-8ghc5 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-8ghc5 in namespace azuredisk-2888 [38;5;243m12/27/22 03:21:23.214[0m Dec 27 03:21:23.281: INFO: deleting PVC "azuredisk-2888"/"pvc-tbvb6" Dec 27 03:21:23.281: INFO: Deleting PersistentVolumeClaim "pvc-tbvb6" ... skipping 37 lines ... Dec 27 03:22:06.716: INFO: PersistentVolumeClaim pvc-2rsj4 found but phase is Pending instead of Bound. Dec 27 03:22:08.752: INFO: PersistentVolumeClaim pvc-2rsj4 found and phase=Bound (4.109039356s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:22:08.752[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:22:08.788[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:22:08.844[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:22:08.845[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m12/27/22 03:22:08.892[0m Dec 27 03:22:08.893: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sdk8c" in namespace "azuredisk-156" to be "Succeeded or Failed" Dec 27 03:22:08.932: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 39.300983ms Dec 27 03:22:10.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074579618s Dec 27 03:22:12.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.07443805s Dec 27 03:22:14.970: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.077485653s Dec 27 03:22:16.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074510328s Dec 27 03:22:18.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 10.075946436s ... skipping 21 lines ... Dec 27 03:23:02.968: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=true. Elapsed: 54.074863976s Dec 27 03:23:04.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 56.076302008s Dec 27 03:23:06.968: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 58.075126083s Dec 27 03:23:08.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 1m0.076505626s Dec 27 03:23:10.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m2.07629665s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:23:10.97[0m Dec 27 03:23:10.972: INFO: Pod "azuredisk-volume-tester-sdk8c" satisfied condition "Succeeded or Failed" Dec 27 03:23:10.973: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-sdk8c" Dec 27 03:23:11.047: INFO: Pod azuredisk-volume-tester-sdk8c has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-sdk8c in namespace azuredisk-156 [38;5;243m12/27/22 03:23:11.047[0m Dec 27 03:23:11.093: INFO: deleting PVC "azuredisk-156"/"pvc-2rsj4" Dec 27 03:23:11.093: INFO: Deleting PersistentVolumeClaim "pvc-2rsj4" ... skipping 38 lines ... Dec 27 03:22:06.716: INFO: PersistentVolumeClaim pvc-2rsj4 found but phase is Pending instead of Bound. Dec 27 03:22:08.752: INFO: PersistentVolumeClaim pvc-2rsj4 found and phase=Bound (4.109039356s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:22:08.752[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:22:08.788[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:22:08.844[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:22:08.845[0m [1mSTEP:[0m checking that the pods command exits with no error [38;5;243m12/27/22 03:22:08.892[0m Dec 27 03:22:08.893: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sdk8c" in namespace "azuredisk-156" to be "Succeeded or Failed" Dec 27 03:22:08.932: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 39.300983ms Dec 27 03:22:10.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074579618s Dec 27 03:22:12.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 4.07443805s Dec 27 03:22:14.970: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 6.077485653s Dec 27 03:22:16.967: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074510328s Dec 27 03:22:18.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Pending", Reason="", readiness=false. Elapsed: 10.075946436s ... skipping 21 lines ... Dec 27 03:23:02.968: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=true. Elapsed: 54.074863976s Dec 27 03:23:04.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 56.076302008s Dec 27 03:23:06.968: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 58.075126083s Dec 27 03:23:08.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Running", Reason="", readiness=false. Elapsed: 1m0.076505626s Dec 27 03:23:10.969: INFO: Pod "azuredisk-volume-tester-sdk8c": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m2.07629665s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:23:10.97[0m Dec 27 03:23:10.972: INFO: Pod "azuredisk-volume-tester-sdk8c" satisfied condition "Succeeded or Failed" Dec 27 03:23:10.973: INFO: deleting Pod "azuredisk-156"/"azuredisk-volume-tester-sdk8c" Dec 27 03:23:11.047: INFO: Pod azuredisk-volume-tester-sdk8c has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-sdk8c in namespace azuredisk-156 [38;5;243m12/27/22 03:23:11.047[0m Dec 27 03:23:11.093: INFO: deleting PVC "azuredisk-156"/"pvc-2rsj4" Dec 27 03:23:11.093: INFO: Deleting PersistentVolumeClaim "pvc-2rsj4" ... skipping 38 lines ... Dec 27 03:23:57.249: INFO: PersistentVolumeClaim pvc-qmf82 found and phase=Bound (4.111652832s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:23:57.249[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:23:57.284[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:23:57.321[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:23:57.323[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:23:57.324[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:23:57.361[0m Dec 27 03:23:57.361: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-f78b9" in namespace "azuredisk-1563" to be "Succeeded or Failed" Dec 27 03:23:57.402: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 41.441757ms Dec 27 03:23:59.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.078099266s Dec 27 03:24:01.441: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.080431815s Dec 27 03:24:03.440: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.078929928s Dec 27 03:24:05.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.078379714s Dec 27 03:24:07.444: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.083259306s ... skipping 26 lines ... Dec 27 03:25:01.438: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=true. Elapsed: 1m4.076766708s Dec 27 03:25:03.444: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.083264736s Dec 27 03:25:05.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m8.077784208s Dec 27 03:25:07.438: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.077232957s Dec 27 03:25:09.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m12.077774019s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:09.439[0m Dec 27 03:25:09.439: INFO: Pod "azuredisk-volume-tester-f78b9" satisfied condition "Succeeded or Failed" Dec 27 03:25:09.439: INFO: deleting Pod "azuredisk-1563"/"azuredisk-volume-tester-f78b9" Dec 27 03:25:09.516: INFO: Pod azuredisk-volume-tester-f78b9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-f78b9 in namespace azuredisk-1563 [38;5;243m12/27/22 03:25:09.517[0m Dec 27 03:25:09.591: INFO: deleting PVC "azuredisk-1563"/"pvc-qmf82" Dec 27 03:25:09.591: INFO: Deleting PersistentVolumeClaim "pvc-qmf82" ... skipping 39 lines ... Dec 27 03:23:57.249: INFO: PersistentVolumeClaim pvc-qmf82 found and phase=Bound (4.111652832s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:23:57.249[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:23:57.284[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:23:57.321[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:23:57.323[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:23:57.324[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:23:57.361[0m Dec 27 03:23:57.361: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-f78b9" in namespace "azuredisk-1563" to be "Succeeded or Failed" Dec 27 03:23:57.402: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 41.441757ms Dec 27 03:23:59.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.078099266s Dec 27 03:24:01.441: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.080431815s Dec 27 03:24:03.440: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.078929928s Dec 27 03:24:05.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.078379714s Dec 27 03:24:07.444: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.083259306s ... skipping 26 lines ... Dec 27 03:25:01.438: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=true. Elapsed: 1m4.076766708s Dec 27 03:25:03.444: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.083264736s Dec 27 03:25:05.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m8.077784208s Dec 27 03:25:07.438: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Running", Reason="", readiness=false. Elapsed: 1m10.077232957s Dec 27 03:25:09.439: INFO: Pod "azuredisk-volume-tester-f78b9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m12.077774019s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:25:09.439[0m Dec 27 03:25:09.439: INFO: Pod "azuredisk-volume-tester-f78b9" satisfied condition "Succeeded or Failed" Dec 27 03:25:09.439: INFO: deleting Pod "azuredisk-1563"/"azuredisk-volume-tester-f78b9" Dec 27 03:25:09.516: INFO: Pod azuredisk-volume-tester-f78b9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-f78b9 in namespace azuredisk-1563 [38;5;243m12/27/22 03:25:09.517[0m Dec 27 03:25:09.591: INFO: deleting PVC "azuredisk-1563"/"pvc-qmf82" Dec 27 03:25:09.591: INFO: Deleting PersistentVolumeClaim "pvc-qmf82" ... skipping 182 lines ... Dec 27 03:25:57.319: INFO: PersistentVolumeClaim pvc-zpck4 found and phase=Bound (4.109606547s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:25:57.319[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:25:57.353[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:25:57.435[0m Dec 27 03:25:57.435: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-2k9p6" in namespace "azuredisk-8010" to be "Error status code" Dec 27 03:25:57.472: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 37.164537ms Dec 27 03:25:59.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071905889s Dec 27 03:26:01.506: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.071630418s Dec 27 03:26:03.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073491739s Dec 27 03:26:05.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074095998s Dec 27 03:26:07.506: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.071621027s ... skipping 17 lines ... Dec 27 03:26:43.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 46.073655816s Dec 27 03:26:45.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 48.072466151s Dec 27 03:26:47.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 50.07199583s Dec 27 03:26:49.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 52.073334174s Dec 27 03:26:51.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 54.074622675s Dec 27 03:26:53.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 56.073652017s Dec 27 03:26:55.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Failed", Reason="", readiness=false. Elapsed: 58.073380615s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:26:55.508[0m Dec 27 03:26:55.508: INFO: Pod "azuredisk-volume-tester-2k9p6" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:26:55.508[0m Dec 27 03:26:55.574: INFO: deleting Pod "azuredisk-8010"/"azuredisk-volume-tester-2k9p6" Dec 27 03:26:55.613: INFO: Pod azuredisk-volume-tester-2k9p6 has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied. At line:1 char:1 + echo $null >> C:\mnt\test-1\data + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ... skipping 48 lines ... Dec 27 03:25:57.319: INFO: PersistentVolumeClaim pvc-zpck4 found and phase=Bound (4.109606547s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:25:57.319[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:25:57.353[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:25:57.396[0m [1mSTEP:[0m checking that the pod's command exits with an error [38;5;243m12/27/22 03:25:57.435[0m Dec 27 03:25:57.435: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-2k9p6" in namespace "azuredisk-8010" to be "Error status code" Dec 27 03:25:57.472: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 37.164537ms Dec 27 03:25:59.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.071905889s Dec 27 03:26:01.506: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.071630418s Dec 27 03:26:03.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073491739s Dec 27 03:26:05.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074095998s Dec 27 03:26:07.506: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.071621027s ... skipping 17 lines ... Dec 27 03:26:43.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 46.073655816s Dec 27 03:26:45.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 48.072466151s Dec 27 03:26:47.507: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=true. Elapsed: 50.07199583s Dec 27 03:26:49.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 52.073334174s Dec 27 03:26:51.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 54.074622675s Dec 27 03:26:53.509: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Running", Reason="", readiness=false. Elapsed: 56.073652017s Dec 27 03:26:55.508: INFO: Pod "azuredisk-volume-tester-2k9p6": Phase="Failed", Reason="", readiness=false. Elapsed: 58.073380615s [1mSTEP:[0m Saw pod failure [38;5;243m12/27/22 03:26:55.508[0m Dec 27 03:26:55.508: INFO: Pod "azuredisk-volume-tester-2k9p6" satisfied condition "Error status code" [1mSTEP:[0m checking that pod logs contain expected message [38;5;243m12/27/22 03:26:55.508[0m Dec 27 03:26:55.574: INFO: deleting Pod "azuredisk-8010"/"azuredisk-volume-tester-2k9p6" Dec 27 03:26:55.613: INFO: Pod azuredisk-volume-tester-2k9p6 has the following logs: out-file : Access to the path 'C:\mnt\test-1\data' is denied. At line:1 char:1 + echo $null >> C:\mnt\test-1\data + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ... skipping 509 lines ... Dec 27 03:34:43.700: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-kdc2r-685b4c69c\" is progressing."}}, CollisionCount:(*int32)(nil)} Dec 27 03:34:45.700: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-kdc2r-685b4c69c\" is progressing."}}, CollisionCount:(*int32)(nil)} [1mSTEP:[0m checking that the pod is running [38;5;243m12/27/22 03:34:47.768[0m [1mSTEP:[0m check pod exec [38;5;243m12/27/22 03:34:47.845[0m Dec 27 03:34:47.846: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt' Dec 27 03:34:48.696: INFO: rc: 1 Dec 27 03:34:48.697: INFO: Error waiting for output "hello world\r\n" in pod "azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt": error running /usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Dec 27 03:34:50.698: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt' Dec 27 03:34:51.341: INFO: stderr: "" Dec 27 03:34:51.341: INFO: stdout: "hello world\r\n" [1mSTEP:[0m deleting the pod for deployment [38;5;243m12/27/22 03:34:51.341[0m Dec 27 03:34:51.342: INFO: Deleting pod "azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt" in namespace "azuredisk-5894" ... skipping 111 lines ... Dec 27 03:34:43.700: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-kdc2r-685b4c69c\" is progressing."}}, CollisionCount:(*int32)(nil)} Dec 27 03:34:45.700: INFO: deployment status: v1.DeploymentStatus{ObservedGeneration:1, Replicas:1, UpdatedReplicas:1, ReadyReplicas:0, AvailableReplicas:0, UnavailableReplicas:1, Conditions:[]v1.DeploymentCondition{v1.DeploymentCondition{Type:"Available", Status:"False", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"MinimumReplicasUnavailable", Message:"Deployment does not have minimum availability."}, v1.DeploymentCondition{Type:"Progressing", Status:"True", LastUpdateTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), LastTransitionTime:time.Date(2022, time.December, 27, 3, 34, 5, 0, time.Local), Reason:"ReplicaSetUpdated", Message:"ReplicaSet \"azuredisk-volume-tester-kdc2r-685b4c69c\" is progressing."}}, CollisionCount:(*int32)(nil)} [1mSTEP:[0m checking that the pod is running [38;5;243m12/27/22 03:34:47.768[0m [1mSTEP:[0m check pod exec [38;5;243m12/27/22 03:34:47.845[0m Dec 27 03:34:47.846: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt' Dec 27 03:34:48.696: INFO: rc: 1 Dec 27 03:34:48.697: INFO: Error waiting for output "hello world\r\n" in pod "azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt": error running /usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt: Command stdout: stderr: The system cannot find the file specified. command terminated with exit code 1 error: exit status 1. Dec 27 03:34:50.698: INFO: Running '/usr/local/bin/kubectl --server=https://kubetest-mwpb3kdi.canadacentral.cloudapp.azure.com --kubeconfig=/root/tmp3913537060/kubeconfig/kubeconfig.canadacentral.json --namespace=azuredisk-5894 exec azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt -- cmd /c type C:\mnt\test-1\data.txt' Dec 27 03:34:51.341: INFO: stderr: "" Dec 27 03:34:51.341: INFO: stdout: "hello world\r\n" [1mSTEP:[0m deleting the pod for deployment [38;5;243m12/27/22 03:34:51.341[0m Dec 27 03:34:51.342: INFO: Deleting pod "azuredisk-volume-tester-kdc2r-685b4c69c-c5qqt" in namespace "azuredisk-5894" ... skipping 339 lines ... Dec 27 03:37:13.741: INFO: PersistentVolumeClaim pvc-scjnf found and phase=Bound (4.108472748s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:37:13.741[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:37:13.776[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:37:13.848[0m Dec 27 03:37:13.848: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-f2lgd" in namespace "azuredisk-9183" to be "Succeeded or Failed" Dec 27 03:37:13.885: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 37.254362ms Dec 27 03:37:15.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.07461624s Dec 27 03:37:17.924: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.075357058s Dec 27 03:37:19.921: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.07322866s Dec 27 03:37:21.921: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.072543862s Dec 27 03:37:23.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.073847762s ... skipping 24 lines ... Dec 27 03:38:13.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=true. Elapsed: 1m0.074648827s Dec 27 03:38:15.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m2.074426307s Dec 27 03:38:17.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.073535941s Dec 27 03:38:19.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.07489697s Dec 27 03:38:21.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m8.073392024s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:38:21.922[0m Dec 27 03:38:21.922: INFO: Pod "azuredisk-volume-tester-f2lgd" satisfied condition "Succeeded or Failed" Dec 27 03:38:21.922: INFO: deleting Pod "azuredisk-9183"/"azuredisk-volume-tester-f2lgd" Dec 27 03:38:22.040: INFO: Pod azuredisk-volume-tester-f2lgd has the following logs: hello world hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-f2lgd in namespace azuredisk-9183 [38;5;243m12/27/22 03:38:22.04[0m ... skipping 87 lines ... Dec 27 03:37:13.741: INFO: PersistentVolumeClaim pvc-scjnf found and phase=Bound (4.108472748s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:37:13.741[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:37:13.776[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:37:13.81[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:37:13.848[0m Dec 27 03:37:13.848: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-f2lgd" in namespace "azuredisk-9183" to be "Succeeded or Failed" Dec 27 03:37:13.885: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 37.254362ms Dec 27 03:37:15.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.07461624s Dec 27 03:37:17.924: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.075357058s Dec 27 03:37:19.921: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.07322866s Dec 27 03:37:21.921: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.072543862s Dec 27 03:37:23.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.073847762s ... skipping 24 lines ... Dec 27 03:38:13.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=true. Elapsed: 1m0.074648827s Dec 27 03:38:15.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m2.074426307s Dec 27 03:38:17.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m4.073535941s Dec 27 03:38:19.923: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Running", Reason="", readiness=false. Elapsed: 1m6.07489697s Dec 27 03:38:21.922: INFO: Pod "azuredisk-volume-tester-f2lgd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 1m8.073392024s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:38:21.922[0m Dec 27 03:38:21.922: INFO: Pod "azuredisk-volume-tester-f2lgd" satisfied condition "Succeeded or Failed" Dec 27 03:38:21.922: INFO: deleting Pod "azuredisk-9183"/"azuredisk-volume-tester-f2lgd" Dec 27 03:38:22.040: INFO: Pod azuredisk-volume-tester-f2lgd has the following logs: hello world hello world hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-f2lgd in namespace azuredisk-9183 [38;5;243m12/27/22 03:38:22.04[0m ... skipping 95 lines ... Dec 27 03:39:26.629: INFO: PersistentVolumeClaim pvc-b5kzh found but phase is Pending instead of Bound. Dec 27 03:39:28.664: INFO: PersistentVolumeClaim pvc-b5kzh found and phase=Bound (4.105885302s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:39:28.664[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:39:28.699[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:39:28.733[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:39:28.734[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:39:28.771[0m Dec 27 03:39:28.772: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dlggf" in namespace "azuredisk-7743" to be "Succeeded or Failed" Dec 27 03:39:28.811: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 39.002002ms Dec 27 03:39:30.846: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074758946s Dec 27 03:39:32.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.075739106s Dec 27 03:39:34.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.075169888s Dec 27 03:39:36.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.075723832s Dec 27 03:39:38.848: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.076016318s ... skipping 15 lines ... Dec 27 03:40:10.846: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=true. Elapsed: 42.074603255s Dec 27 03:40:12.876: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=true. Elapsed: 44.104309286s Dec 27 03:40:14.845: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=false. Elapsed: 46.073788337s Dec 27 03:40:16.848: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=false. Elapsed: 48.076033921s Dec 27 03:40:18.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.075016597s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:40:18.847[0m Dec 27 03:40:18.847: INFO: Pod "azuredisk-volume-tester-dlggf" satisfied condition "Succeeded or Failed" [1mSTEP:[0m Checking Prow test resource group [38;5;243m12/27/22 03:40:18.847[0m 2022/12/27 03:40:18 Running in Prow, converting AZURE_CREDENTIALS to AZURE_CREDENTIAL_FILE 2022/12/27 03:40:18 Reading credentials file /etc/azure-cred/credentials [1mSTEP:[0m Prow test resource group: kubetest-mwpb3kdi [38;5;243m12/27/22 03:40:18.849[0m [1mSTEP:[0m Creating external resource group: azuredisk-csi-driver-test-2f016cdd-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:40:18.849[0m [1mSTEP:[0m creating volume snapshot class with external rg azuredisk-csi-driver-test-2f016cdd-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:40:19.879[0m ... skipping 13 lines ... Dec 27 03:40:39.190: INFO: PersistentVolumeClaim pvc-b6sgg found and phase=Bound (4.106246723s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:40:39.19[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:40:39.225[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:40:39.259[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:40:39.26[0m [1mSTEP:[0m deploying a pod with a volume restored from the snapshot [38;5;243m12/27/22 03:40:39.26[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:40:39.298[0m Dec 27 03:40:39.298: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-h78g2" in namespace "azuredisk-7743" to be "Succeeded or Failed" Dec 27 03:40:39.334: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 36.006929ms Dec 27 03:40:41.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072754352s Dec 27 03:40:43.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.073321968s Dec 27 03:40:45.372: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073703066s Dec 27 03:40:47.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.072754806s Dec 27 03:40:49.369: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.071508616s ... skipping 10 lines ... Dec 27 03:41:11.370: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=true. Elapsed: 32.072281961s Dec 27 03:41:13.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=true. Elapsed: 34.072767332s Dec 27 03:41:15.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=false. Elapsed: 36.072838951s Dec 27 03:41:17.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=false. Elapsed: 38.072672758s Dec 27 03:41:19.369: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 40.071154957s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:41:19.369[0m Dec 27 03:41:19.369: INFO: Pod "azuredisk-volume-tester-h78g2" satisfied condition "Succeeded or Failed" Dec 27 03:41:19.369: INFO: deleting Pod "azuredisk-7743"/"azuredisk-volume-tester-h78g2" Dec 27 03:41:19.437: INFO: Pod azuredisk-volume-tester-h78g2 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-h78g2 in namespace azuredisk-7743 [38;5;243m12/27/22 03:41:19.437[0m Dec 27 03:41:19.485: INFO: deleting PVC "azuredisk-7743"/"pvc-b6sgg" Dec 27 03:41:19.485: INFO: Deleting PersistentVolumeClaim "pvc-b6sgg" ... skipping 60 lines ... Dec 27 03:39:26.629: INFO: PersistentVolumeClaim pvc-b5kzh found but phase is Pending instead of Bound. Dec 27 03:39:28.664: INFO: PersistentVolumeClaim pvc-b5kzh found and phase=Bound (4.105885302s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:39:28.664[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:39:28.699[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:39:28.733[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:39:28.734[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:39:28.771[0m Dec 27 03:39:28.772: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-dlggf" in namespace "azuredisk-7743" to be "Succeeded or Failed" Dec 27 03:39:28.811: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 39.002002ms Dec 27 03:39:30.846: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.074758946s Dec 27 03:39:32.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.075739106s Dec 27 03:39:34.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.075169888s Dec 27 03:39:36.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.075723832s Dec 27 03:39:38.848: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.076016318s ... skipping 15 lines ... Dec 27 03:40:10.846: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=true. Elapsed: 42.074603255s Dec 27 03:40:12.876: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=true. Elapsed: 44.104309286s Dec 27 03:40:14.845: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=false. Elapsed: 46.073788337s Dec 27 03:40:16.848: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Running", Reason="", readiness=false. Elapsed: 48.076033921s Dec 27 03:40:18.847: INFO: Pod "azuredisk-volume-tester-dlggf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 50.075016597s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:40:18.847[0m Dec 27 03:40:18.847: INFO: Pod "azuredisk-volume-tester-dlggf" satisfied condition "Succeeded or Failed" [1mSTEP:[0m Checking Prow test resource group [38;5;243m12/27/22 03:40:18.847[0m [1mSTEP:[0m Prow test resource group: kubetest-mwpb3kdi [38;5;243m12/27/22 03:40:18.849[0m [1mSTEP:[0m Creating external resource group: azuredisk-csi-driver-test-2f016cdd-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:40:18.849[0m [1mSTEP:[0m creating volume snapshot class with external rg azuredisk-csi-driver-test-2f016cdd-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:40:19.879[0m [1mSTEP:[0m setting up the VolumeSnapshotClass [38;5;243m12/27/22 03:40:19.879[0m [1mSTEP:[0m creating a VolumeSnapshotClass [38;5;243m12/27/22 03:40:19.879[0m ... skipping 11 lines ... Dec 27 03:40:39.190: INFO: PersistentVolumeClaim pvc-b6sgg found and phase=Bound (4.106246723s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:40:39.19[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:40:39.225[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:40:39.259[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:40:39.26[0m [1mSTEP:[0m deploying a pod with a volume restored from the snapshot [38;5;243m12/27/22 03:40:39.26[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:40:39.298[0m Dec 27 03:40:39.298: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-h78g2" in namespace "azuredisk-7743" to be "Succeeded or Failed" Dec 27 03:40:39.334: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 36.006929ms Dec 27 03:40:41.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.072754352s Dec 27 03:40:43.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.073321968s Dec 27 03:40:45.372: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073703066s Dec 27 03:40:47.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.072754806s Dec 27 03:40:49.369: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.071508616s ... skipping 10 lines ... Dec 27 03:41:11.370: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=true. Elapsed: 32.072281961s Dec 27 03:41:13.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=true. Elapsed: 34.072767332s Dec 27 03:41:15.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=false. Elapsed: 36.072838951s Dec 27 03:41:17.371: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Running", Reason="", readiness=false. Elapsed: 38.072672758s Dec 27 03:41:19.369: INFO: Pod "azuredisk-volume-tester-h78g2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 40.071154957s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:41:19.369[0m Dec 27 03:41:19.369: INFO: Pod "azuredisk-volume-tester-h78g2" satisfied condition "Succeeded or Failed" Dec 27 03:41:19.369: INFO: deleting Pod "azuredisk-7743"/"azuredisk-volume-tester-h78g2" Dec 27 03:41:19.437: INFO: Pod azuredisk-volume-tester-h78g2 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-h78g2 in namespace azuredisk-7743 [38;5;243m12/27/22 03:41:19.437[0m Dec 27 03:41:19.485: INFO: deleting PVC "azuredisk-7743"/"pvc-b6sgg" Dec 27 03:41:19.485: INFO: Deleting PersistentVolumeClaim "pvc-b6sgg" ... skipping 59 lines ... Dec 27 03:44:00.066: INFO: PersistentVolumeClaim pvc-6wvzt found but phase is Pending instead of Bound. Dec 27 03:44:02.101: INFO: PersistentVolumeClaim pvc-6wvzt found and phase=Bound (4.105028699s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:44:02.101[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:44:02.135[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:44:02.169[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:44:02.17[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:44:02.206[0m Dec 27 03:44:02.207: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ts2wx" in namespace "azuredisk-3162" to be "Succeeded or Failed" Dec 27 03:44:02.267: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 60.467906ms Dec 27 03:44:04.305: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.098875269s Dec 27 03:44:06.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.09532303s Dec 27 03:44:08.304: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.097423279s Dec 27 03:44:10.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.095424043s Dec 27 03:44:12.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.095389276s ... skipping 19 lines ... Dec 27 03:44:52.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=true. Elapsed: 50.096047056s Dec 27 03:44:54.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=true. Elapsed: 52.096162166s Dec 27 03:44:56.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=false. Elapsed: 54.096598481s Dec 27 03:44:58.304: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=false. Elapsed: 56.097859876s Dec 27 03:45:00.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 58.095379176s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:45:00.302[0m Dec 27 03:45:00.302: INFO: Pod "azuredisk-volume-tester-ts2wx" satisfied condition "Succeeded or Failed" [1mSTEP:[0m Checking Prow test resource group [38;5;243m12/27/22 03:45:00.302[0m 2022/12/27 03:45:00 Running in Prow, converting AZURE_CREDENTIALS to AZURE_CREDENTIAL_FILE 2022/12/27 03:45:00 Reading credentials file /etc/azure-cred/credentials [1mSTEP:[0m Prow test resource group: kubetest-mwpb3kdi [38;5;243m12/27/22 03:45:00.303[0m [1mSTEP:[0m Creating external resource group: azuredisk-csi-driver-test-d6c3f48f-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:45:00.304[0m [1mSTEP:[0m creating volume snapshot class with external rg azuredisk-csi-driver-test-d6c3f48f-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:45:01.249[0m ... skipping 30 lines ... [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:45:42.686[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:45:42.72[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m Set pod anti-affinity to make sure two pods are scheduled on different nodes [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m deploying a pod with a volume restored from the snapshot [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:45:42.79[0m Dec 27 03:45:42.790: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sbhl9" in namespace "azuredisk-3162" to be "Succeeded or Failed" Dec 27 03:45:42.824: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 34.263389ms Dec 27 03:45:44.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069668278s Dec 27 03:45:46.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.069257463s Dec 27 03:45:48.864: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073678274s Dec 27 03:45:50.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.069189139s Dec 27 03:45:52.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068561704s ... skipping 11 lines ... Dec 27 03:46:16.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=true. Elapsed: 34.070201075s Dec 27 03:46:18.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=true. Elapsed: 36.070123323s Dec 27 03:46:20.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=false. Elapsed: 38.069520204s Dec 27 03:46:22.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=false. Elapsed: 40.069844012s Dec 27 03:46:24.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 42.069420512s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:46:24.86[0m Dec 27 03:46:24.860: INFO: Pod "azuredisk-volume-tester-sbhl9" satisfied condition "Succeeded or Failed" Dec 27 03:46:24.860: INFO: deleting Pod "azuredisk-3162"/"azuredisk-volume-tester-sbhl9" Dec 27 03:46:24.929: INFO: Pod azuredisk-volume-tester-sbhl9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-sbhl9 in namespace azuredisk-3162 [38;5;243m12/27/22 03:46:24.929[0m Dec 27 03:46:24.977: INFO: deleting PVC "azuredisk-3162"/"pvc-59mps" Dec 27 03:46:24.977: INFO: Deleting PersistentVolumeClaim "pvc-59mps" ... skipping 56 lines ... Dec 27 03:44:00.066: INFO: PersistentVolumeClaim pvc-6wvzt found but phase is Pending instead of Bound. Dec 27 03:44:02.101: INFO: PersistentVolumeClaim pvc-6wvzt found and phase=Bound (4.105028699s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:44:02.101[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:44:02.135[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:44:02.169[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:44:02.17[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:44:02.206[0m Dec 27 03:44:02.207: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-ts2wx" in namespace "azuredisk-3162" to be "Succeeded or Failed" Dec 27 03:44:02.267: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 60.467906ms Dec 27 03:44:04.305: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.098875269s Dec 27 03:44:06.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.09532303s Dec 27 03:44:08.304: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.097423279s Dec 27 03:44:10.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.095424043s Dec 27 03:44:12.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.095389276s ... skipping 19 lines ... Dec 27 03:44:52.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=true. Elapsed: 50.096047056s Dec 27 03:44:54.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=true. Elapsed: 52.096162166s Dec 27 03:44:56.303: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=false. Elapsed: 54.096598481s Dec 27 03:44:58.304: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Running", Reason="", readiness=false. Elapsed: 56.097859876s Dec 27 03:45:00.302: INFO: Pod "azuredisk-volume-tester-ts2wx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 58.095379176s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:45:00.302[0m Dec 27 03:45:00.302: INFO: Pod "azuredisk-volume-tester-ts2wx" satisfied condition "Succeeded or Failed" [1mSTEP:[0m Checking Prow test resource group [38;5;243m12/27/22 03:45:00.302[0m [1mSTEP:[0m Prow test resource group: kubetest-mwpb3kdi [38;5;243m12/27/22 03:45:00.303[0m [1mSTEP:[0m Creating external resource group: azuredisk-csi-driver-test-d6c3f48f-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:45:00.304[0m [1mSTEP:[0m creating volume snapshot class with external rg azuredisk-csi-driver-test-d6c3f48f-8598-11ed-a0fc-be71e99d69a4 [38;5;243m12/27/22 03:45:01.249[0m [1mSTEP:[0m setting up the VolumeSnapshotClass [38;5;243m12/27/22 03:45:01.25[0m [1mSTEP:[0m creating a VolumeSnapshotClass [38;5;243m12/27/22 03:45:01.25[0m ... skipping 28 lines ... [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:45:42.686[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:45:42.72[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m setting up the pod [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m Set pod anti-affinity to make sure two pods are scheduled on different nodes [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m deploying a pod with a volume restored from the snapshot [38;5;243m12/27/22 03:45:42.754[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:45:42.79[0m Dec 27 03:45:42.790: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-sbhl9" in namespace "azuredisk-3162" to be "Succeeded or Failed" Dec 27 03:45:42.824: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 34.263389ms Dec 27 03:45:44.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.069668278s Dec 27 03:45:46.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.069257463s Dec 27 03:45:48.864: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.073678274s Dec 27 03:45:50.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.069189139s Dec 27 03:45:52.859: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068561704s ... skipping 11 lines ... Dec 27 03:46:16.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=true. Elapsed: 34.070201075s Dec 27 03:46:18.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=true. Elapsed: 36.070123323s Dec 27 03:46:20.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=false. Elapsed: 38.069520204s Dec 27 03:46:22.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Running", Reason="", readiness=false. Elapsed: 40.069844012s Dec 27 03:46:24.860: INFO: Pod "azuredisk-volume-tester-sbhl9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 42.069420512s [1mSTEP:[0m Saw pod success [38;5;243m12/27/22 03:46:24.86[0m Dec 27 03:46:24.860: INFO: Pod "azuredisk-volume-tester-sbhl9" satisfied condition "Succeeded or Failed" Dec 27 03:46:24.860: INFO: deleting Pod "azuredisk-3162"/"azuredisk-volume-tester-sbhl9" Dec 27 03:46:24.929: INFO: Pod azuredisk-volume-tester-sbhl9 has the following logs: hello world [1mSTEP:[0m Deleting pod azuredisk-volume-tester-sbhl9 in namespace azuredisk-3162 [38;5;243m12/27/22 03:46:24.929[0m Dec 27 03:46:24.977: INFO: deleting PVC "azuredisk-3162"/"pvc-59mps" Dec 27 03:46:24.977: INFO: Deleting PersistentVolumeClaim "pvc-59mps" ... skipping 79 lines ... Dec 27 03:48:39.078: INFO: PersistentVolumeClaim pvc-2snts found but phase is Pending instead of Bound. Dec 27 03:48:41.114: INFO: PersistentVolumeClaim pvc-2snts found and phase=Bound (4.109980999s) [1mSTEP:[0m checking the PVC [38;5;243m12/27/22 03:48:41.114[0m [1mSTEP:[0m validating provisioned PV [38;5;243m12/27/22 03:48:41.148[0m [1mSTEP:[0m checking the PV [38;5;243m12/27/22 03:48:41.182[0m [1mSTEP:[0m deploying the pod [38;5;243m12/27/22 03:48:41.182[0m [1mSTEP:[0m checking that the pod's command exits with no error [38;5;243m12/27/22 03:48:41.22[0m Dec 27 03:48:41.220: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-77mtc" in namespace "azuredisk-9700" to be "Succeeded or Failed" Dec 27 03:48:41.253: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 33.704329ms Dec 27 03:48:43.290: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.070012521s Dec 27 03:48:45.291: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.070732576s Dec 27 03:48:47.289: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.068795002s Dec 27 03:48:49.290: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.070060083s Dec 27 03:48:51.289: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.068893623s ... skipping 19 lines ... Dec 27 03:49:31.291: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 50.071063543s Dec 27 03:49:33.288: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 52.068648148s Dec 27 03:49:35.290: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 54.069841827s Dec 27 03:49:37.291: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 56.071394697s Dec 27 03:49:39.291: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 58.071693002s Dec 27 03:49:41.292: INFO: Pod "azuredisk-volume-tester-77mtc": Phase="Pending", Reason="", readiness=false. Elapsed: 1m0.071980802s {"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":"2022-12-27T03:49:43Z"} ++ early_exit_handler ++ '[' -n 170 ']' ++ kill -TERM 170 ++ cleanup_dind ++ [[ true == \t\r\u\e ]] ++ echo 'Cleaning up after docker' ... skipping 4 lines ...