sigs.k8s.io/azuredisk-csi-driver PR #180 chewong-pull-azuredisk-csi-driver-e2e-multi-az #1191801407074734080
Recent runs || View in Spyglass
Recent runs || View in Spyglass
error during make e2e-test: exit status 2
from junit_runner.xml
Filter through log files
Build
Check APIReachability
Deferred TearDown
DumpClusterLogs
IsUp
TearDown
TearDown Previous
Timeout
Up
kubectl version
list nodes
test setup
... skipping 574 lines ... I1105 20:21:53.717] Nov 5 20:21:53.717: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:21:55.797] Nov 5 20:21:55.797: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:21:57.876] Nov 5 20:21:57.876: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:21:59.955] Nov 5 20:21:59.955: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:22:02.035] Nov 5 20:22:02.035: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:22:04.115] Nov 5 20:22:04.114: INFO: PersistentVolumeClaim pvc-9g8k7 found but phase is Pending instead of Bound. I1105 20:22:06.115] Nov 5 20:22:06.115: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-9g8k7] not all in phase Bound within 5m0s I1105 20:22:06.115] [AfterEach] [multi-az] I1105 20:22:06.116] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:22:06.116] STEP: Collecting events from namespace "azuredisk-8307". I1105 20:22:06.213] STEP: Found 3 events. I1105 20:22:06.213] Nov 5 20:22:06.213: INFO: At 2019-11-05 20:17:04 +0000 UTC - event for pvc-9g8k7: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:22:06.213] Nov 5 20:22:06.213: INFO: At 2019-11-05 20:17:04 +0000 UTC - event for pvc-9g8k7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8307/pvc-9g8k7" I1105 20:22:06.214] Nov 5 20:22:06.213: INFO: At 2019-11-05 20:17:05 +0000 UTC - event for pvc-9g8k7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8307-disk.csi.azure.com-dynamic-sc-5dsj4": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-bf33a003-e1f4-4125-b63b-8b0663bda0f8' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:22:06.293] Nov 5 20:22:06.293: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:22:06.293] Nov 5 20:22:06.293: INFO: I1105 20:22:06.533] Nov 5 20:22:06.532: INFO: I1105 20:22:06.533] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:22:06.624] Nov 5 20:22:06.620: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:3450,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:21:37 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:21:37 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:21:37 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:21:37 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:22:06.624] Nov 5 20:22:06.621: INFO: ... skipping 175 lines ... I1105 20:22:27.758] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:22:27.758] [multi-az] I1105 20:22:27.758] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 20:22:27.758] should create a volume on demand [It] I1105 20:22:27.758] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:78 I1105 20:22:27.758] I1105 20:22:27.759] Unexpected error: I1105 20:22:27.759] <*errors.errorString | 0xc000916a40>: { I1105 20:22:27.759] s: "PersistentVolumeClaims [pvc-9g8k7] not all in phase Bound within 5m0s", I1105 20:22:27.759] } I1105 20:22:27.759] PersistentVolumeClaims [pvc-9g8k7] not all in phase Bound within 5m0s I1105 20:22:27.759] occurred I1105 20:22:27.759] ... skipping 161 lines ... I1105 20:27:17.718] Nov 5 20:27:17.718: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:19.798] Nov 5 20:27:19.797: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:21.877] Nov 5 20:27:21.877: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:23.957] Nov 5 20:27:23.957: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:26.036] Nov 5 20:27:26.036: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:28.116] Nov 5 20:27:28.115: INFO: PersistentVolumeClaim pvc-tvv9z found but phase is Pending instead of Bound. I1105 20:27:30.116] Nov 5 20:27:30.116: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-tvv9z] not all in phase Bound within 5m0s I1105 20:27:30.116] [AfterEach] [single-az] I1105 20:27:30.117] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:27:30.117] STEP: Collecting events from namespace "azuredisk-1082". I1105 20:27:30.221] STEP: Found 3 events. I1105 20:27:30.221] Nov 5 20:27:30.221: INFO: At 2019-11-05 20:22:28 +0000 UTC - event for pvc-tvv9z: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:27:30.222] Nov 5 20:27:30.221: INFO: At 2019-11-05 20:22:28 +0000 UTC - event for pvc-tvv9z: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1082/pvc-tvv9z" I1105 20:27:30.222] Nov 5 20:27:30.221: INFO: At 2019-11-05 20:22:28 +0000 UTC - event for pvc-tvv9z: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-1082-disk.csi.azure.com-dynamic-sc-9lfxl": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-1992216b-619e-4853-9cbf-6eed3e7ef781' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:27:30.299] Nov 5 20:27:30.299: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:27:30.299] Nov 5 20:27:30.299: INFO: I1105 20:27:30.534] Nov 5 20:27:30.534: INFO: I1105 20:27:30.534] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:27:30.708] Nov 5 20:27:30.705: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:4354,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:26:38 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:26:38 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:26:38 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:26:38 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:27:30.708] Nov 5 20:27:30.705: INFO: ... skipping 175 lines ... I1105 20:27:51.599] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:27:51.599] [single-az] I1105 20:27:51.600] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 20:27:51.600] should create a raw block volume on demand [It] I1105 20:27:51.600] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:101 I1105 20:27:51.600] I1105 20:27:51.600] Unexpected error: I1105 20:27:51.600] <*errors.errorString | 0xc000a10b70>: { I1105 20:27:51.600] s: "PersistentVolumeClaims [pvc-tvv9z] not all in phase Bound within 5m0s", I1105 20:27:51.600] } I1105 20:27:51.601] PersistentVolumeClaims [pvc-tvv9z] not all in phase Bound within 5m0s I1105 20:27:51.601] occurred I1105 20:27:51.601] ... skipping 161 lines ... I1105 20:32:41.587] Nov 5 20:32:41.587: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:43.667] Nov 5 20:32:43.666: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:45.747] Nov 5 20:32:45.746: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:47.826] Nov 5 20:32:47.826: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:49.905] Nov 5 20:32:49.905: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:51.985] Nov 5 20:32:51.984: INFO: PersistentVolumeClaim pvc-vrjw8 found but phase is Pending instead of Bound. I1105 20:32:53.985] Nov 5 20:32:53.985: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-vrjw8] not all in phase Bound within 5m0s I1105 20:32:53.985] [AfterEach] [multi-az] I1105 20:32:53.986] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:32:53.986] STEP: Collecting events from namespace "azuredisk-8704". I1105 20:32:54.065] STEP: Found 3 events. I1105 20:32:54.066] Nov 5 20:32:54.065: INFO: At 2019-11-05 20:27:52 +0000 UTC - event for pvc-vrjw8: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8704/pvc-vrjw8" I1105 20:32:54.066] Nov 5 20:32:54.065: INFO: At 2019-11-05 20:27:52 +0000 UTC - event for pvc-vrjw8: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:32:54.067] Nov 5 20:32:54.065: INFO: At 2019-11-05 20:27:52 +0000 UTC - event for pvc-vrjw8: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8704-disk.csi.azure.com-dynamic-sc-njm8g": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-407455f4-7515-4f11-accd-f7a60ea556ce' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:32:54.145] Nov 5 20:32:54.145: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:32:54.145] Nov 5 20:32:54.145: INFO: I1105 20:32:54.379] Nov 5 20:32:54.379: INFO: I1105 20:32:54.379] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:32:54.462] Nov 5 20:32:54.459: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:5431,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:32:39 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:32:39 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:32:39 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:32:39 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:32:54.462] Nov 5 20:32:54.459: INFO: ... skipping 175 lines ... I1105 20:33:15.276] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:33:15.276] [multi-az] I1105 20:33:15.276] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 20:33:15.276] [env] should retain PV with reclaimPolicy "Retain" [It] I1105 20:33:15.276] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:240 I1105 20:33:15.276] I1105 20:33:15.277] Unexpected error: I1105 20:33:15.277] <*errors.errorString | 0xc000a3c170>: { I1105 20:33:15.277] s: "PersistentVolumeClaims [pvc-vrjw8] not all in phase Bound within 5m0s", I1105 20:33:15.277] } I1105 20:33:15.277] PersistentVolumeClaims [pvc-vrjw8] not all in phase Bound within 5m0s I1105 20:33:15.277] occurred I1105 20:33:15.277] ... skipping 161 lines ... I1105 20:38:05.288] Nov 5 20:38:05.288: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:07.370] Nov 5 20:38:07.369: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:09.449] Nov 5 20:38:09.449: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:11.528] Nov 5 20:38:11.528: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:13.607] Nov 5 20:38:13.607: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:15.686] Nov 5 20:38:15.686: INFO: PersistentVolumeClaim pvc-fzxvb found but phase is Pending instead of Bound. I1105 20:38:17.687] Nov 5 20:38:17.686: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-fzxvb] not all in phase Bound within 5m0s I1105 20:38:17.687] [AfterEach] [single-az] I1105 20:38:17.687] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:38:17.687] STEP: Collecting events from namespace "azuredisk-5245". I1105 20:38:17.766] STEP: Found 3 events. I1105 20:38:17.767] Nov 5 20:38:17.766: INFO: At 2019-11-05 20:33:15 +0000 UTC - event for pvc-fzxvb: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-5245/pvc-fzxvb" I1105 20:38:17.767] Nov 5 20:38:17.766: INFO: At 2019-11-05 20:33:16 +0000 UTC - event for pvc-fzxvb: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:38:17.767] Nov 5 20:38:17.766: INFO: At 2019-11-05 20:33:16 +0000 UTC - event for pvc-fzxvb: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-5245-disk.csi.azure.com-dynamic-sc-ps5s2": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-becb7110-0575-4408-878d-f00430c8097b' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:38:17.845] Nov 5 20:38:17.845: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:38:17.845] Nov 5 20:38:17.845: INFO: I1105 20:38:18.081] Nov 5 20:38:18.081: INFO: I1105 20:38:18.081] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:38:18.163] Nov 5 20:38:18.160: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:6331,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:37:40 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:37:40 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:37:40 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:37:40 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:38:18.163] Nov 5 20:38:18.160: INFO: ... skipping 175 lines ... I1105 20:38:38.941] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:38:38.941] [single-az] I1105 20:38:38.942] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 20:38:38.942] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [It] I1105 20:38:38.942] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:151 I1105 20:38:38.942] I1105 20:38:38.942] Unexpected error: I1105 20:38:38.942] <*errors.errorString | 0xc000cb51d0>: { I1105 20:38:38.942] s: "PersistentVolumeClaims [pvc-fzxvb] not all in phase Bound within 5m0s", I1105 20:38:38.942] } I1105 20:38:38.943] PersistentVolumeClaims [pvc-fzxvb] not all in phase Bound within 5m0s I1105 20:38:38.943] occurred I1105 20:38:38.943] ... skipping 152 lines ... I1105 20:43:28.987] Nov 5 20:43:28.986: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:31.071] Nov 5 20:43:31.071: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:33.155] Nov 5 20:43:33.155: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:35.240] Nov 5 20:43:35.240: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:37.324] Nov 5 20:43:37.324: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:39.409] Nov 5 20:43:39.409: INFO: PersistentVolumeClaim pvc-mkkrb found but phase is Pending instead of Bound. I1105 20:43:41.409] Nov 5 20:43:41.409: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-mkkrb] not all in phase Bound within 5m0s I1105 20:43:41.410] [AfterEach] [multi-az] I1105 20:43:41.410] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:43:41.410] STEP: Collecting events from namespace "azuredisk-507". I1105 20:43:41.500] STEP: Found 3 events. I1105 20:43:41.500] Nov 5 20:43:41.500: INFO: At 2019-11-05 20:38:39 +0000 UTC - event for pvc-mkkrb: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:43:41.500] Nov 5 20:43:41.500: INFO: At 2019-11-05 20:38:39 +0000 UTC - event for pvc-mkkrb: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-507/pvc-mkkrb" I1105 20:43:41.501] Nov 5 20:43:41.500: INFO: At 2019-11-05 20:38:39 +0000 UTC - event for pvc-mkkrb: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-507-disk.csi.azure.com-dynamic-sc-qkrmz": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-5b8b4b6c-a77e-4ceb-9226-ec3f3ed561ec' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:43:41.584] Nov 5 20:43:41.583: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:43:41.584] Nov 5 20:43:41.583: INFO: I1105 20:43:41.915] Nov 5 20:43:41.915: INFO: I1105 20:43:41.916] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:43:42.003] Nov 5 20:43:41.999: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:7407,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:43:41 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:43:41 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:43:41 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:43:41 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:43:42.003] Nov 5 20:43:42.000: INFO: ... skipping 175 lines ... I1105 20:44:03.335] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:44:03.335] [multi-az] I1105 20:44:03.336] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 20:44:03.336] should create a deployment object, write and read to it, delete the pod and write and read to it again [It] I1105 20:44:03.336] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:193 I1105 20:44:03.336] I1105 20:44:03.336] Unexpected error: I1105 20:44:03.336] <*errors.errorString | 0xc0008c9170>: { I1105 20:44:03.337] s: "PersistentVolumeClaims [pvc-mkkrb] not all in phase Bound within 5m0s", I1105 20:44:03.337] } I1105 20:44:03.337] PersistentVolumeClaims [pvc-mkkrb] not all in phase Bound within 5m0s I1105 20:44:03.337] occurred I1105 20:44:03.337] ... skipping 214 lines ... I1105 20:44:33.879] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 20:44:33.879] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:36 I1105 20:44:33.879] [env] should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" [It] I1105 20:44:33.879] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:100 I1105 20:44:33.879] I1105 20:44:33.879] Test Panicked I1105 20:44:33.879] runtime error: invalid memory address or nil pointer dereference I1105 20:44:33.879] /usr/local/go/src/runtime/panic.go:82 I1105 20:44:33.880] I1105 20:44:33.880] Full Stack Trace I1105 20:44:33.880] /usr/local/go/src/runtime/panic.go:522 +0x1b5 I1105 20:44:33.880] sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites.(*TestPersistentVolumeClaim).Cleanup(0xc0010761e0) I1105 20:44:33.880] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:313 +0x3b ... skipping 171 lines ... I1105 20:49:24.160] Nov 5 20:49:24.160: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:26.252] Nov 5 20:49:26.252: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:28.331] Nov 5 20:49:28.331: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:30.411] Nov 5 20:49:30.411: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:32.490] Nov 5 20:49:32.490: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:34.570] Nov 5 20:49:34.569: INFO: PersistentVolumeClaim pvc-m2g49 found but phase is Pending instead of Bound. I1105 20:49:36.570] Nov 5 20:49:36.570: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-m2g49] not all in phase Bound within 5m0s I1105 20:49:36.570] [AfterEach] [multi-az] I1105 20:49:36.570] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:49:36.571] STEP: Collecting events from namespace "azuredisk-6880". I1105 20:49:36.652] STEP: Found 3 events. I1105 20:49:36.653] Nov 5 20:49:36.652: INFO: At 2019-11-05 20:44:34 +0000 UTC - event for pvc-m2g49: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-6880/pvc-m2g49" I1105 20:49:36.653] Nov 5 20:49:36.652: INFO: At 2019-11-05 20:44:34 +0000 UTC - event for pvc-m2g49: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:49:36.654] Nov 5 20:49:36.652: INFO: At 2019-11-05 20:44:34 +0000 UTC - event for pvc-m2g49: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-6880-disk.csi.azure.com-dynamic-sc-b2lt8": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-679b1f36-48d8-49c5-a05f-83d3128d4fe8' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:49:36.731] Nov 5 20:49:36.731: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:49:36.731] Nov 5 20:49:36.731: INFO: I1105 20:49:36.965] Nov 5 20:49:36.965: INFO: I1105 20:49:36.966] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:49:37.047] Nov 5 20:49:37.044: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:8326,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:48:42 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:48:42 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:48:42 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:48:42 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:49:37.048] Nov 5 20:49:37.045: INFO: ... skipping 175 lines ... I1105 20:49:57.899] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:49:57.899] [multi-az] I1105 20:49:57.899] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 20:49:57.900] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [It] I1105 20:49:57.900] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:151 I1105 20:49:57.900] I1105 20:49:57.900] Unexpected error: I1105 20:49:57.900] <*errors.errorString | 0xc000ce7640>: { I1105 20:49:57.900] s: "PersistentVolumeClaims [pvc-m2g49] not all in phase Bound within 5m0s", I1105 20:49:57.901] } I1105 20:49:57.901] PersistentVolumeClaims [pvc-m2g49] not all in phase Bound within 5m0s I1105 20:49:57.901] occurred I1105 20:49:57.901] ... skipping 161 lines ... I1105 20:54:47.427] Nov 5 20:54:47.427: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:49.507] Nov 5 20:54:49.506: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:51.586] Nov 5 20:54:51.586: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:53.665] Nov 5 20:54:53.665: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:55.745] Nov 5 20:54:55.744: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:57.823] Nov 5 20:54:57.823: INFO: PersistentVolumeClaim pvc-6nqs8 found but phase is Pending instead of Bound. I1105 20:54:59.824] Nov 5 20:54:59.823: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-6nqs8] not all in phase Bound within 5m0s I1105 20:54:59.824] [AfterEach] [single-az] I1105 20:54:59.824] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 20:54:59.825] STEP: Collecting events from namespace "azuredisk-8958". I1105 20:54:59.904] STEP: Found 3 events. I1105 20:54:59.904] Nov 5 20:54:59.904: INFO: At 2019-11-05 20:49:58 +0000 UTC - event for pvc-6nqs8: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 20:54:59.904] Nov 5 20:54:59.904: INFO: At 2019-11-05 20:49:58 +0000 UTC - event for pvc-6nqs8: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8958/pvc-6nqs8" I1105 20:54:59.905] Nov 5 20:54:59.904: INFO: At 2019-11-05 20:49:58 +0000 UTC - event for pvc-6nqs8: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8958-disk.csi.azure.com-dynamic-sc-jphrz": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-8a9d1e51-fbae-4b8e-86b0-e707a779262a' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 20:54:59.982] Nov 5 20:54:59.982: INFO: POD NODE PHASE GRACE CONDITIONS I1105 20:54:59.982] Nov 5 20:54:59.982: INFO: I1105 20:55:00.218] Nov 5 20:55:00.217: INFO: I1105 20:55:00.218] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 20:55:00.299] Nov 5 20:55:00.296: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:9403,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:54:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:54:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:54:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:54:43 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 20:55:00.300] Nov 5 20:55:00.296: INFO: ... skipping 175 lines ... I1105 20:55:21.194] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 20:55:21.194] [single-az] I1105 20:55:21.195] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 20:55:21.195] should create a deployment object, write and read to it, delete the pod and write and read to it again [It] I1105 20:55:21.195] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:193 I1105 20:55:21.195] I1105 20:55:21.195] Unexpected error: I1105 20:55:21.196] <*errors.errorString | 0xc0007b1120>: { I1105 20:55:21.196] s: "PersistentVolumeClaims [pvc-6nqs8] not all in phase Bound within 5m0s", I1105 20:55:21.196] } I1105 20:55:21.196] PersistentVolumeClaims [pvc-6nqs8] not all in phase Bound within 5m0s I1105 20:55:21.196] occurred I1105 20:55:21.196] ... skipping 160 lines ... I1105 21:00:09.845] Nov 5 21:00:09.845: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:11.924] Nov 5 21:00:11.924: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:14.003] Nov 5 21:00:14.003: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:16.082] Nov 5 21:00:16.081: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:18.160] Nov 5 21:00:18.160: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:20.240] Nov 5 21:00:20.240: INFO: PersistentVolumeClaim pvc-hqwk4 found but phase is Pending instead of Bound. I1105 21:00:22.240] Nov 5 21:00:22.240: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-hqwk4] not all in phase Bound within 5m0s I1105 21:00:22.241] [AfterEach] [multi-az] I1105 21:00:22.241] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:00:22.241] STEP: Collecting events from namespace "azuredisk-9464". I1105 21:00:22.321] STEP: Found 3 events. I1105 21:00:22.322] Nov 5 21:00:22.321: INFO: At 2019-11-05 20:55:21 +0000 UTC - event for pvc-hqwk4: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9464/pvc-hqwk4" I1105 21:00:22.322] Nov 5 21:00:22.321: INFO: At 2019-11-05 20:55:21 +0000 UTC - event for pvc-hqwk4: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:00:22.322] Nov 5 21:00:22.321: INFO: At 2019-11-05 20:55:22 +0000 UTC - event for pvc-hqwk4: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-9464-disk.csi.azure.com-dynamic-sc-5ks6s": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-def232e0-f8dd-4d3c-8404-450062786564' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:00:22.399] Nov 5 21:00:22.399: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:00:22.400] Nov 5 21:00:22.399: INFO: I1105 21:00:22.641] Nov 5 21:00:22.641: INFO: I1105 21:00:22.642] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:00:22.723] Nov 5 21:00:22.720: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:10303,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 20:59:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 20:59:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 20:59:43 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 20:59:43 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:00:22.723] Nov 5 21:00:22.720: INFO: ... skipping 175 lines ... I1105 21:00:43.573] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:00:43.573] [multi-az] I1105 21:00:43.573] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 21:00:43.573] should create a raw block volume on demand [It] I1105 21:00:43.573] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:101 I1105 21:00:43.573] I1105 21:00:43.573] Unexpected error: I1105 21:00:43.573] <*errors.errorString | 0xc0006b5660>: { I1105 21:00:43.574] s: "PersistentVolumeClaims [pvc-hqwk4] not all in phase Bound within 5m0s", I1105 21:00:43.574] } I1105 21:00:43.574] PersistentVolumeClaims [pvc-hqwk4] not all in phase Bound within 5m0s I1105 21:00:43.574] occurred I1105 21:00:43.574] ... skipping 161 lines ... I1105 21:05:33.574] Nov 5 21:05:33.574: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:35.653] Nov 5 21:05:35.653: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:37.732] Nov 5 21:05:37.732: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:39.813] Nov 5 21:05:39.813: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:41.893] Nov 5 21:05:41.892: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:43.972] Nov 5 21:05:43.972: INFO: PersistentVolumeClaim pvc-zkl6h found but phase is Pending instead of Bound. I1105 21:05:45.972] Nov 5 21:05:45.972: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-zkl6h] not all in phase Bound within 5m0s I1105 21:05:45.973] [AfterEach] [single-az] I1105 21:05:45.973] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:05:45.973] STEP: Collecting events from namespace "azuredisk-6633". I1105 21:05:46.052] STEP: Found 3 events. I1105 21:05:46.053] Nov 5 21:05:46.052: INFO: At 2019-11-05 21:00:44 +0000 UTC - event for pvc-zkl6h: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-6633/pvc-zkl6h" I1105 21:05:46.053] Nov 5 21:05:46.052: INFO: At 2019-11-05 21:00:44 +0000 UTC - event for pvc-zkl6h: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:05:46.054] Nov 5 21:05:46.052: INFO: At 2019-11-05 21:00:44 +0000 UTC - event for pvc-zkl6h: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-6633-disk.csi.azure.com-dynamic-sc-wp4x5": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-2b5dcbda-7a31-417c-ab49-147fe574629a' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:05:46.131] Nov 5 21:05:46.131: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:05:46.131] Nov 5 21:05:46.131: INFO: I1105 21:05:46.369] Nov 5 21:05:46.369: INFO: I1105 21:05:46.369] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:05:46.451] Nov 5 21:05:46.447: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:11377,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:05:44 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:05:44 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:05:44 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:05:44 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:05:46.451] Nov 5 21:05:46.448: INFO: ... skipping 175 lines ... I1105 21:06:07.354] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:06:07.354] [single-az] I1105 21:06:07.354] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 21:06:07.355] should create a volume on demand and mount it as readOnly in a pod [It] I1105 21:06:07.355] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:126 I1105 21:06:07.355] I1105 21:06:07.355] Unexpected error: I1105 21:06:07.355] <*errors.errorString | 0xc0008c8b20>: { I1105 21:06:07.355] s: "PersistentVolumeClaims [pvc-zkl6h] not all in phase Bound within 5m0s", I1105 21:06:07.355] } I1105 21:06:07.355] PersistentVolumeClaims [pvc-zkl6h] not all in phase Bound within 5m0s I1105 21:06:07.356] occurred I1105 21:06:07.356] ... skipping 161 lines ... I1105 21:10:57.349] Nov 5 21:10:57.349: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:10:59.425] Nov 5 21:10:59.425: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:11:01.502] Nov 5 21:11:01.502: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:11:03.578] Nov 5 21:11:03.578: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:11:05.654] Nov 5 21:11:05.654: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:11:07.731] Nov 5 21:11:07.731: INFO: PersistentVolumeClaim pvc-m4z2v found but phase is Pending instead of Bound. I1105 21:11:09.731] Nov 5 21:11:09.731: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-m4z2v] not all in phase Bound within 5m0s I1105 21:11:09.732] [AfterEach] [single-az] I1105 21:11:09.732] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:11:09.732] STEP: Collecting events from namespace "azuredisk-9582". I1105 21:11:09.809] STEP: Found 3 events. I1105 21:11:09.809] Nov 5 21:11:09.809: INFO: At 2019-11-05 21:06:08 +0000 UTC - event for pvc-m4z2v: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9582/pvc-m4z2v" I1105 21:11:09.809] Nov 5 21:11:09.809: INFO: At 2019-11-05 21:06:08 +0000 UTC - event for pvc-m4z2v: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:11:09.810] Nov 5 21:11:09.809: INFO: At 2019-11-05 21:06:08 +0000 UTC - event for pvc-m4z2v: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-9582-disk.csi.azure.com-dynamic-sc-xrwd8": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-90f0ea65-b7d9-4beb-abb1-52e61bb3b021' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:11:09.885] Nov 5 21:11:09.885: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:11:09.886] Nov 5 21:11:09.885: INFO: I1105 21:11:10.112] Nov 5 21:11:10.112: INFO: I1105 21:11:10.112] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:11:10.212] Nov 5 21:11:10.209: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:12284,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:10:45 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:10:45 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:10:45 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:10:45 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:11:10.212] Nov 5 21:11:10.209: INFO: ... skipping 175 lines ... I1105 21:11:30.769] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:11:30.769] [single-az] I1105 21:11:30.769] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 21:11:30.769] [env] should retain PV with reclaimPolicy "Retain" [It] I1105 21:11:30.769] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:240 I1105 21:11:30.769] I1105 21:11:30.770] Unexpected error: I1105 21:11:30.770] <*errors.errorString | 0xc000a2d860>: { I1105 21:11:30.770] s: "PersistentVolumeClaims [pvc-m4z2v] not all in phase Bound within 5m0s", I1105 21:11:30.770] } I1105 21:11:30.770] PersistentVolumeClaims [pvc-m4z2v] not all in phase Bound within 5m0s I1105 21:11:30.770] occurred I1105 21:11:30.770] ... skipping 125 lines ... I1105 21:16:19.578] Nov 5 21:16:19.578: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:21.657] Nov 5 21:16:21.656: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:23.736] Nov 5 21:16:23.736: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:25.815] Nov 5 21:16:25.815: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:27.903] Nov 5 21:16:27.903: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:29.982] Nov 5 21:16:29.982: INFO: PersistentVolumeClaim pvc-n9hsv found but phase is Pending instead of Bound. I1105 21:16:31.982] Nov 5 21:16:31.982: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-n9hsv] not all in phase Bound within 5m0s I1105 21:16:31.983] [AfterEach] [single-az] I1105 21:16:31.983] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:16:31.983] STEP: Collecting events from namespace "azuredisk-3372". I1105 21:16:32.062] STEP: Found 3 events. I1105 21:16:32.062] Nov 5 21:16:32.062: INFO: At 2019-11-05 21:11:31 +0000 UTC - event for pvc-n9hsv: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:16:32.062] Nov 5 21:16:32.062: INFO: At 2019-11-05 21:11:31 +0000 UTC - event for pvc-n9hsv: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-3372/pvc-n9hsv" I1105 21:16:32.063] Nov 5 21:16:32.062: INFO: At 2019-11-05 21:11:31 +0000 UTC - event for pvc-n9hsv: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-3372-disk.csi.azure.com-dynamic-sc-mklzd": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-886ff5f0-a896-492a-8061-9c66ac06d55e' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:16:32.141] Nov 5 21:16:32.141: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:16:32.141] Nov 5 21:16:32.141: INFO: I1105 21:16:32.603] Nov 5 21:16:32.603: INFO: I1105 21:16:32.603] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:16:32.685] Nov 5 21:16:32.682: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:13181,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:15:46 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:15:46 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:15:46 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:15:46 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:16:32.685] Nov 5 21:16:32.682: INFO: ... skipping 175 lines ... I1105 21:16:54.528] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:16:54.528] [single-az] I1105 21:16:54.528] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 21:16:54.528] should create a volume on demand [It] I1105 21:16:54.528] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:78 I1105 21:16:54.528] I1105 21:16:54.528] Unexpected error: I1105 21:16:54.529] <*errors.errorString | 0xc000697090>: { I1105 21:16:54.529] s: "PersistentVolumeClaims [pvc-n9hsv] not all in phase Bound within 5m0s", I1105 21:16:54.529] } I1105 21:16:54.529] PersistentVolumeClaims [pvc-n9hsv] not all in phase Bound within 5m0s I1105 21:16:54.529] occurred I1105 21:16:54.529] ... skipping 23 lines ... I1105 21:17:07.171] Nov 5 21:17:07.170: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-xkxzt] to have phase Bound I1105 21:17:07.254] Nov 5 21:17:07.254: INFO: PersistentVolumeClaim pvc-xkxzt found and phase=Bound (83.536933ms) I1105 21:17:07.254] STEP: checking the PVC I1105 21:17:07.338] STEP: validating provisioned PV I1105 21:17:07.429] STEP: checking the PV I1105 21:17:07.429] STEP: deploying the pod I1105 21:17:07.522] STEP: checking that the pods command exits with an error I1105 21:17:07.522] Nov 5 21:17:07.522: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-gxg4d" in namespace "azuredisk-5349" to be "Error status code" I1105 21:17:07.606] Nov 5 21:17:07.605: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 83.639334ms I1105 21:17:09.690] Nov 5 21:17:09.690: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.168057746s I1105 21:17:11.774] Nov 5 21:17:11.774: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.252400256s I1105 21:17:13.858] Nov 5 21:17:13.858: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.336531165s I1105 21:17:15.944] Nov 5 21:17:15.943: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.421717582s I1105 21:17:18.032] Nov 5 21:17:18.032: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 10.509912522s ... skipping 24 lines ... I1105 21:18:10.219] Nov 5 21:18:10.218: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m2.696560961s I1105 21:18:12.303] Nov 5 21:18:12.303: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m4.781284973s I1105 21:18:14.388] Nov 5 21:18:14.388: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m6.865894884s I1105 21:18:16.472] Nov 5 21:18:16.472: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m8.950381495s I1105 21:18:18.557] Nov 5 21:18:18.556: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m11.034798704s I1105 21:18:20.641] Nov 5 21:18:20.641: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Pending", Reason="", readiness=false. Elapsed: 1m13.119370815s I1105 21:18:22.726] Nov 5 21:18:22.725: INFO: Pod "azuredisk-volume-tester-gxg4d": Phase="Failed", Reason="", readiness=false. Elapsed: 1m15.203703724s I1105 21:18:22.726] STEP: Saw pod failure I1105 21:18:22.726] Nov 5 21:18:22.725: INFO: Pod "azuredisk-volume-tester-gxg4d" satisfied condition "Error status code" I1105 21:18:22.726] STEP: checking that pod logs contain expected message I1105 21:18:22.816] Nov 5 21:18:22.816: INFO: deleting Pod "azuredisk-5349"/"azuredisk-volume-tester-gxg4d" I1105 21:18:22.905] Nov 5 21:18:22.905: INFO: Pod azuredisk-volume-tester-gxg4d has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system I1105 21:18:22.905] I1105 21:18:22.906] STEP: Deleting pod azuredisk-volume-tester-gxg4d in namespace azuredisk-5349 I1105 21:18:23.009] STEP: deleting PV "azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772" ... skipping 116 lines ... I1105 21:27:57.547] Nov 5 21:27:57.546: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m34.445765928s) I1105 21:28:02.631] Nov 5 21:28:02.630: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m39.52982617s) I1105 21:28:07.710] Nov 5 21:28:07.710: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m44.609054776s) I1105 21:28:12.789] Nov 5 21:28:12.789: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m49.688579483s) I1105 21:28:17.869] Nov 5 21:28:17.869: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m54.768464794s) I1105 21:28:22.950] Nov 5 21:28:22.950: INFO: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 found and phase=Bound (9m59.849166488s) I1105 21:28:27.950] Nov 5 21:28:27.950: INFO: Unexpected error occurred: PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 still exists within 10m0s I1105 21:28:27.951] [AfterEach] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 21:28:27.951] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:28:27.951] STEP: Collecting events from namespace "azuredisk-5349". I1105 21:28:28.030] STEP: Found 7 events. I1105 21:28:28.030] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:17:07 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {default-scheduler } Scheduled: Successfully assigned azuredisk-5349/azuredisk-volume-tester-gxg4d to k8s-agentpool-97435445-vmss000001 I1105 21:28:28.031] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:17:22 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772" : attachment timeout for volume /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/disks/pre-provisioned-readOnly I1105 21:28:28.031] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:17:48 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772" I1105 21:28:28.032] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:18:19 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {kubelet k8s-agentpool-97435445-vmss000001} Pulling: Pulling image "docker.io/library/busybox:1.29" I1105 21:28:28.032] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:18:19 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {kubelet k8s-agentpool-97435445-vmss000001} Pulled: Successfully pulled image "docker.io/library/busybox:1.29" I1105 21:28:28.032] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:18:21 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {kubelet k8s-agentpool-97435445-vmss000001} Created: Created container volume-tester I1105 21:28:28.032] Nov 5 21:28:28.030: INFO: At 2019-11-05 21:18:21 +0000 UTC - event for azuredisk-volume-tester-gxg4d: {kubelet k8s-agentpool-97435445-vmss000001} Started: Started container volume-tester I1105 21:28:28.110] Nov 5 21:28:28.110: INFO: POD NODE PHASE GRACE CONDITIONS ... skipping 180 lines ... I1105 21:28:55.209] • Failure [720.681 seconds] I1105 21:28:55.209] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 21:28:55.209] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:36 I1105 21:28:55.209] [env] should use a pre-provisioned volume and mount it as readOnly in a pod [It] I1105 21:28:55.210] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:66 I1105 21:28:55.210] I1105 21:28:55.210] Unexpected error: I1105 21:28:55.210] <*errors.errorString | 0xc000ce6730>: { I1105 21:28:55.210] s: "PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 still exists within 10m0s", I1105 21:28:55.211] } I1105 21:28:55.211] PersistentVolume azuredisk-5349-disk.csi.azure.com-preprovsioned-pv-xb772 still exists within 10m0s I1105 21:28:55.211] occurred I1105 21:28:55.211] ... skipping 161 lines ... I1105 21:33:45.262] Nov 5 21:33:45.262: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:47.342] Nov 5 21:33:47.342: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:49.422] Nov 5 21:33:49.421: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:51.501] Nov 5 21:33:51.500: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:53.581] Nov 5 21:33:53.580: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:55.660] Nov 5 21:33:55.660: INFO: PersistentVolumeClaim pvc-xcqrj found but phase is Pending instead of Bound. I1105 21:33:57.661] Nov 5 21:33:57.660: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-xcqrj] not all in phase Bound within 5m0s I1105 21:33:57.661] [AfterEach] [single-az] I1105 21:33:57.661] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:33:57.661] STEP: Collecting events from namespace "azuredisk-1513". I1105 21:33:57.747] STEP: Found 3 events. I1105 21:33:57.747] Nov 5 21:33:57.746: INFO: At 2019-11-05 21:28:55 +0000 UTC - event for pvc-xcqrj: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1513/pvc-xcqrj" I1105 21:33:57.747] Nov 5 21:33:57.746: INFO: At 2019-11-05 21:28:55 +0000 UTC - event for pvc-xcqrj: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:33:57.748] Nov 5 21:33:57.746: INFO: At 2019-11-05 21:28:56 +0000 UTC - event for pvc-xcqrj: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-1513-disk.csi.azure.com-dynamic-sc-fr4h7": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-3c352b9d-7d5f-4b7f-afe2-585dacc93888' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:33:57.826] Nov 5 21:33:57.826: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:33:57.826] Nov 5 21:33:57.826: INFO: I1105 21:33:58.068] Nov 5 21:33:58.068: INFO: I1105 21:33:58.069] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:33:58.162] Nov 5 21:33:58.159: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:16343,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:33:49 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:33:49 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:33:49 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:33:49 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:33:58.162] Nov 5 21:33:58.159: INFO: ... skipping 175 lines ... I1105 21:34:19.105] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:34:19.105] [single-az] I1105 21:34:19.105] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 21:34:19.105] should delete PV with reclaimPolicy "Delete" [It] I1105 21:34:19.105] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:221 I1105 21:34:19.105] I1105 21:34:19.106] Unexpected error: I1105 21:34:19.106] <*errors.errorString | 0xc000916f50>: { I1105 21:34:19.106] s: "PersistentVolumeClaims [pvc-xcqrj] not all in phase Bound within 5m0s", I1105 21:34:19.106] } I1105 21:34:19.106] PersistentVolumeClaims [pvc-xcqrj] not all in phase Bound within 5m0s I1105 21:34:19.106] occurred I1105 21:34:19.106] ... skipping 143 lines ... I1105 21:39:08.217] Nov 5 21:39:08.217: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:10.296] Nov 5 21:39:10.296: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:12.376] Nov 5 21:39:12.375: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:14.455] Nov 5 21:39:14.455: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:16.538] Nov 5 21:39:16.538: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:18.632] Nov 5 21:39:18.631: INFO: PersistentVolumeClaim pvc-rxsnk found but phase is Pending instead of Bound. I1105 21:39:20.632] Nov 5 21:39:20.632: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-rxsnk] not all in phase Bound within 5m0s I1105 21:39:20.632] [AfterEach] [multi-az] I1105 21:39:20.632] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:39:20.633] STEP: Collecting events from namespace "azuredisk-3090". I1105 21:39:20.712] STEP: Found 3 events. I1105 21:39:20.712] Nov 5 21:39:20.712: INFO: At 2019-11-05 21:34:19 +0000 UTC - event for pvc-rxsnk: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:39:20.712] Nov 5 21:39:20.712: INFO: At 2019-11-05 21:34:19 +0000 UTC - event for pvc-rxsnk: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-3090/pvc-rxsnk" I1105 21:39:20.713] Nov 5 21:39:20.712: INFO: At 2019-11-05 21:34:19 +0000 UTC - event for pvc-rxsnk: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-3090-disk.csi.azure.com-dynamic-sc-55fv2": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-c4dba06b-be89-41c6-a771-815a56bb0c81' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:39:20.790] Nov 5 21:39:20.790: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:39:20.790] Nov 5 21:39:20.790: INFO: I1105 21:39:21.248] Nov 5 21:39:21.248: INFO: I1105 21:39:21.248] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:39:21.330] Nov 5 21:39:21.327: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:17244,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:38:50 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:38:50 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:38:50 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:38:50 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:39:21.330] Nov 5 21:39:21.327: INFO: ... skipping 175 lines ... I1105 21:39:43.178] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:39:43.178] [multi-az] I1105 21:39:43.178] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 21:39:43.178] should delete PV with reclaimPolicy "Delete" [It] I1105 21:39:43.178] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:221 I1105 21:39:43.178] I1105 21:39:43.178] Unexpected error: I1105 21:39:43.178] <*errors.errorString | 0xc000a3cf40>: { I1105 21:39:43.179] s: "PersistentVolumeClaims [pvc-rxsnk] not all in phase Bound within 5m0s", I1105 21:39:43.179] } I1105 21:39:43.179] PersistentVolumeClaims [pvc-rxsnk] not all in phase Bound within 5m0s I1105 21:39:43.179] occurred I1105 21:39:43.179] ... skipping 161 lines ... I1105 21:44:32.450] Nov 5 21:44:32.450: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:34.524] Nov 5 21:44:34.524: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:36.598] Nov 5 21:44:36.598: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:38.673] Nov 5 21:44:38.673: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:40.748] Nov 5 21:44:40.747: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:42.822] Nov 5 21:44:42.821: INFO: PersistentVolumeClaim pvc-ckvm7 found but phase is Pending instead of Bound. I1105 21:44:44.822] Nov 5 21:44:44.822: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-ckvm7] not all in phase Bound within 5m0s I1105 21:44:44.822] [AfterEach] [multi-az] I1105 21:44:44.822] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 21:44:44.823] STEP: Collecting events from namespace "azuredisk-8482". I1105 21:44:44.896] STEP: Found 3 events. I1105 21:44:44.897] Nov 5 21:44:44.896: INFO: At 2019-11-05 21:39:43 +0000 UTC - event for pvc-ckvm7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8482/pvc-ckvm7" I1105 21:44:44.897] Nov 5 21:44:44.896: INFO: At 2019-11-05 21:39:43 +0000 UTC - event for pvc-ckvm7: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "disk.csi.azure.com" or manually created by system administrator I1105 21:44:44.898] Nov 5 21:44:44.896: INFO: At 2019-11-05 21:39:44 +0000 UTC - event for pvc-ckvm7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-62nrt_3930bc69-0009-11ea-8cf5-829a27ff7d5a } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8482-disk.csi.azure.com-dynamic-sc-xk2nr": rpc error: code = Unknown desc = compute.DisksClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="InvalidAvailabilityZone" Message="The zone(s) '' for resource 'Microsoft.Compute/disks/pvc-c412946c-30a6-4ba1-8382-12c6afc4b96f' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 21:44:44.970] Nov 5 21:44:44.970: INFO: POD NODE PHASE GRACE CONDITIONS I1105 21:44:44.970] Nov 5 21:44:44.970: INFO: I1105 21:44:45.255] Nov 5 21:44:45.255: INFO: I1105 21:44:45.256] Logging node info for node k8s-agentpool-97435445-vmss000000 I1105 21:44:45.331] Nov 5 21:44:45.328: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-97435445-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-97435445-vmss000000,UID:e955dc47-8c8f-4142-9241-3d409f32e42d,ResourceVersion:18143,Generation:0,CreationTimestamp:2019-11-05 20:07:34 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{agentpool: agentpool,beta.kubernetes.io/arch: amd64,beta.kubernetes.io/instance-type: Standard_D4s_v3,beta.kubernetes.io/os: linux,failure-domain.beta.kubernetes.io/region: eastus2,failure-domain.beta.kubernetes.io/zone: 0,kubernetes.azure.com/cluster: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-97435445-vmss000000,kubernetes.io/os: linux,kubernetes.io/role: agent,node-role.kubernetes.io/agent: ,storageprofile: managed,storagetier: Premium_LRS,topology.disk.csi.azure.com/zone: 0,},Annotations:map[string]string{csi.volume.kubernetes.io/nodeid: {"disk.csi.azure.com":"k8s-agentpool-97435445-vmss000000"},node.alpha.kubernetes.io/ttl: 0,volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:10.244.2.0/24,DoNotUse_ExternalID:,ProviderID:azure:///subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-97435445-vmss/virtualMachines/0,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{31036776448 0} {<nil>} BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16797040640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-csi-disk.csi.azure.com: {{8 0} {<nil>} 8 DecimalSI},cpu: {{4 0} {<nil>} 4 DecimalSI},ephemeral-storage: {{27933098757 0} {<nil>} 27933098757 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{16010608640 0} {<nil>} BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 20:08:01 +0000 UTC 2019-11-05 20:08:01 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 21:43:51 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 21:43:51 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 21:43:51 +0000 UTC 2019-11-05 20:07:27 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 21:43:51 +0000 UTC 2019-11-05 20:07:55 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-97435445-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:bfb55325809340228149d2d93f50df58,SystemUUID:CB2ED036-0439-F641-BC7F-640C3638C027,BootID:a917f4d1-549d-471d-b7dc-47ae1715d97d,KernelVersion:4.15.0-1061-azure,OSImage:Ubuntu 16.04.6 LTS,ContainerRuntimeVersion:docker://3.0.6,KubeletVersion:v1.15.0,KubeProxyVersion:v1.15.0,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcrio.azureedge.net/google_containers/hyperkube-amd64@sha256:7f66ed6bd11edd309dad15db1dc906f89035cc9d9ae705c65c98264c775b9a8f gcrio.azureedge.net/google_containers/hyperkube-amd64:v1.15.0] 593352254} {[k8sprowinternal.azurecr.io/azuredisk-csi@sha256:75d4ff5d7cd845d6e810c67796ecb037e852fb849ec1eb5b3194564008e6d1e0 k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887] 286930414} {[k8s.gcr.io/kubernetes-dashboard-amd64@sha256:0ae6b69432e78069c5ce2bcde0fe409c5c4d6f0f4d9cd50a17974fea38898747 k8s.gcr.io/kubernetes-dashboard-amd64:v1.10.1] 121711221} {[k8s.gcr.io/ip-masq-agent-amd64@sha256:269e0fb9d53fd37f7a135d6a55ea265a67279ba218aa148323f015cf70167340 k8s.gcr.io/ip-masq-agent-amd64:v2.3.0] 50144412} {[k8s.gcr.io/metrics-server-amd64@sha256:49a9f12f7067d11f42c803dbe61ed2c1299959ad85cb315b25ff7eef8e6b8892 k8s.gcr.io/metrics-server-amd64:v0.2.1] 42541759} {[k8s.gcr.io/coredns@sha256:e83beb5e43f8513fa735e77ffc5859640baea30a882a11cc75c4c3244a737d3c k8s.gcr.io/coredns:1.5.0] 42488424} {[mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume@sha256:4fd30d43947d4a54fc89ead7985beecfd3c9b2a93a0655a373b1608ab90bd5af mcr.microsoft.com/k8s/flexvolume/keyvault-flexvolume:v0.0.7] 22909487} {[quay.io/k8scsi/livenessprobe@sha256:8c9c8a0f330acc2e558ae6624309447d02522e76aa35af23fa19b88abf4381cb quay.io/k8scsi/livenessprobe:v1.0.2] 17415381} {[quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599 quay.io/k8scsi/csi-node-driver-registrar:v1.1.0] 15815995} {[mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume@sha256:23d8c6033f02a1ecad05127ebdc931bb871264228661bc122704b0974e4d9fdd mcr.microsoft.com/k8s/flexvolume/blobfuse-flexvolume:1.0.8] 1159025} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 21:44:45.332] Nov 5 21:44:45.328: INFO: ... skipping 175 lines ... I1105 21:45:05.857] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 21:45:05.857] [multi-az] I1105 21:45:05.857] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 21:45:05.857] should create a volume on demand and mount it as readOnly in a pod [It] I1105 21:45:05.857] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:126 I1105 21:45:05.858] I1105 21:45:05.858] Unexpected error: I1105 21:45:05.858] <*errors.errorString | 0xc0007f2c10>: { I1105 21:45:05.858] s: "PersistentVolumeClaims [pvc-ckvm7] not all in phase Bound within 5m0s", I1105 21:45:05.858] } I1105 21:45:05.858] PersistentVolumeClaims [pvc-ckvm7] not all in phase Bound within 5m0s I1105 21:45:05.858] occurred I1105 21:45:05.859] ... skipping 6 lines ... I1105 21:45:12.922] make[1]: Leaving directory '/go/src/sigs.k8s.io/azuredisk-csi-driver' I1105 21:45:12.922] 2019/11/05 21:45:12 Azure Disk CSI Driver uninstalled I1105 21:45:12.922] I1105 21:45:12.923] I1105 21:45:12.923] Summarizing 16 Failures: I1105 21:45:12.923] I1105 21:45:12.923] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a volume on demand I1105 21:45:12.923] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.923] I1105 21:45:12.923] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a raw block volume on demand I1105 21:45:12.924] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.924] I1105 21:45:12.924] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] [env] should retain PV with reclaimPolicy "Retain" I1105 21:45:12.924] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.924] I1105 21:45:12.924] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node I1105 21:45:12.924] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.925] I1105 21:45:12.925] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a deployment object, write and read to it, delete the pod and write and read to it again I1105 21:45:12.925] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.925] I1105 21:45:12.925] [Panic!] [azuredisk-csi-e2e] [single-az] Pre-Provisioned [It] [env] should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" I1105 21:45:12.925] /usr/local/go/src/runtime/panic.go:82 I1105 21:45:12.925] I1105 21:45:12.926] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node I1105 21:45:12.926] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.926] I1105 21:45:12.926] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a deployment object, write and read to it, delete the pod and write and read to it again I1105 21:45:12.926] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.926] I1105 21:45:12.927] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a raw block volume on demand I1105 21:45:12.927] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.927] I1105 21:45:12.927] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a volume on demand and mount it as readOnly in a pod I1105 21:45:12.927] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.927] I1105 21:45:12.928] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] [env] should retain PV with reclaimPolicy "Retain" I1105 21:45:12.928] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.928] I1105 21:45:12.928] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a volume on demand I1105 21:45:12.928] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.929] I1105 21:45:12.929] [Fail] [azuredisk-csi-e2e] [single-az] Pre-Provisioned [It] [env] should use a pre-provisioned volume and mount it as readOnly in a pod I1105 21:45:12.929] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:353 I1105 21:45:12.929] I1105 21:45:12.929] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should delete PV with reclaimPolicy "Delete" I1105 21:45:12.930] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.930] I1105 21:45:12.930] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should delete PV with reclaimPolicy "Delete" I1105 21:45:12.930] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.930] I1105 21:45:12.930] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a volume on demand and mount it as readOnly in a pod I1105 21:45:12.931] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 21:45:12.931] I1105 21:45:12.931] Ran 16 of 16 Specs in 5444.012 seconds I1105 21:45:12.931] FAIL! -- 0 Passed | 16 Failed | 0 Pending | 0 Skipped I1105 21:45:12.931] --- FAIL: TestE2E (5444.01s) I1105 21:45:12.931] FAIL I1105 21:45:12.931] FAIL sigs.k8s.io/azuredisk-csi-driver/test/e2e 5444.141s W1105 21:45:13.147] make: *** [Makefile:59: e2e-test] Error 1 W1105 21:45:13.147] 2019/11/05 21:45:13 process.go:155: Step 'make e2e-test' finished in 1h33m35.936241521s W1105 21:45:13.148] 2019/11/05 21:45:13 azure.go:912: Skippng DumpClusterLogs due to CCM not being enabled. W1105 21:45:13.148] 2019/11/05 21:45:13 azure.go:906: Deleting resource group: kubetest-bbefcda2-0003-11ea-9fa5-0242359b656b. W1105 21:56:08.176] 2019/11/05 21:56:08 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1105 21:56:08.176] 2019/11/05 21:56:08 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1105 21:56:08.814] 2019/11/05 21:56:08 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 637.738541ms W1105 21:56:08.814] 2019/11/05 21:56:08 main.go:319: Something went wrong: encountered 1 errors: [error during make e2e-test: exit status 2] W1105 21:56:08.816] Traceback (most recent call last): W1105 21:56:08.817] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module> W1105 21:56:08.817] main(parse_args()) W1105 21:56:08.817] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1105 21:56:08.817] mode.start(runner_args) W1105 21:56:08.818] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1105 21:56:08.818] check_env(env, self.command, *args) W1105 21:56:08.818] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1105 21:56:08.818] subprocess.check_call(cmd, env=env) W1105 21:56:08.818] File "/usr/lib/python2.7/subprocess.py", line 190, in check_call W1105 21:56:08.818] raise CalledProcessError(retcode, cmd) W1105 21:56:08.819] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--build=bazel', '--up', '--down', '--test', '--deployment=acsengine', '--provider=skeleton', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--ginkgo-parallel=1', '--acsengine-agentpoolcount=2', '--acsengine-admin-username=azureuser', '--acsengine-creds=/etc/azure-cred/credentials', '--acsengine-orchestratorRelease=1.16', '--acsengine-mastervmsize=Standard_DS2_v2', '--acsengine-agentvmsize=Standard_D4s_v3', '--acsengine-location=eastus2', '--acsengine-public-key=/etc/azure-ssh/azure-ssh-pub', '--acsengine-template-url=https://raw.githubusercontent.com/kubernetes-sigs/cloud-provider-azure/master/tests/k8s-azure/manifest/linux-vmss-multi-zones.json', '--acsengine-download-url=https://github.com/Azure/aks-engine/releases/download/v0.39.1/aks-engine-v0.39.1-linux-amd64.tar.gz', '--test-azure-disk-csi-driver=True', '--test_args=--ginkgo.focus=\\[multi-az\\]', '--timeout=420m')' returned non-zero exit status 1 E1105 21:56:08.827] Command failed I1105 21:56:08.827] process 683 exited with code 1 after 138.4m E1105 21:56:08.827] FAIL: chewong-pull-azuredisk-csi-driver-e2e-multi-az I1105 21:56:08.827] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1105 21:56:09.444] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1105 21:56:09.477] process 13994 exited with code 0 after 0.0m I1105 21:56:09.477] Call: gcloud config get-value account I1105 21:56:09.730] process 14006 exited with code 0 after 0.0m I1105 21:56:09.730] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1105 21:56:09.730] Upload result and artifacts... I1105 21:56:09.730] Gubernator results at https://gubernator.k8s.io/build/kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191801407074734080 I1105 21:56:09.730] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191801407074734080/artifacts W1105 21:56:10.645] CommandException: One or more URLs matched no objects. E1105 21:56:10.732] Command failed I1105 21:56:10.732] process 14018 exited with code 1 after 0.0m W1105 21:56:10.732] Remote dir gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191801407074734080/artifacts not exist yet I1105 21:56:10.732] Call: gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191801407074734080/artifacts I1105 21:56:12.158] process 14162 exited with code 0 after 0.0m I1105 21:56:12.158] Call: git rev-parse HEAD I1105 21:56:12.161] process 14691 exited with code 0 after 0.0m ... skipping 21 lines ...