sigs.k8s.io/azuredisk-csi-driver PR #180 chewong-pull-azuredisk-csi-driver-e2e-multi-az #1191521311436836864
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 305 lines ... I1105 01:36:56.798] pod/tiller-deploy-54c96cb5df-8d9fs condition met I1105 01:36:56.799] helm version I1105 01:36:56.856] Client: &version.Version{SemVer:"v2.11.0", GitCommit:"2e55dbe1fdb5fdb96b75ff144a339489417b146b", GitTreeState:"clean"} I1105 01:36:57.805] Server: &version.Version{SemVer:"v2.11.0", GitCommit:"2e55dbe1fdb5fdb96b75ff144a339489417b146b", GitTreeState:"clean"} I1105 01:36:57.807] # Only build and push the image if it does not exist in the registry I1105 01:36:57.807] docker pull k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887 || make azuredisk-container push I1105 01:36:58.033] Error response from daemon: manifest for k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887 not found: manifest unknown: manifest unknown I1105 01:36:58.037] make[2]: Entering directory '/go/src/sigs.k8s.io/azuredisk-csi-driver' I1105 01:36:58.042] if [ ! -d ./vendor ]; then dep ensure -vendor-only; fi I1105 01:36:58.043] CGO_ENABLED=0 GOOS=linux go build -a -ldflags "-X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.driverVersion=e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.gitCommit=3e3ed045c6faa509dbd8d2890ee9f56aa2934887 -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.buildDate=2019-11-05T01:36:58Z -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.DriverName=disk.csi.azure.com -X sigs.k8s.io/azuredisk-csi-driver/pkg/azuredisk.topologyKey=topology.disk.csi.azure.com/zone -extldflags "-static"" -o _output/azurediskplugin ./pkg/azurediskplugin I1105 01:37:33.633] docker build --no-cache -t k8sprowinternal.azurecr.io/azuredisk-csi:e2e-3e3ed045c6faa509dbd8d2890ee9f56aa2934887 -f ./pkg/azurediskplugin/Dockerfile . I1105 01:37:35.788] Sending build context to Docker daemon 214.4MB I1105 01:37:35.830] Step 1/6 : FROM aksrepos.azurecr.io/fundamental/base-ubuntu:v0.0.5 ... skipping 352 lines ... I1105 01:44:08.565] Nov 5 01:44:08.565: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:10.643] Nov 5 01:44:10.643: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:12.721] Nov 5 01:44:12.721: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:14.799] Nov 5 01:44:14.799: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:16.877] Nov 5 01:44:16.877: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:18.961] Nov 5 01:44:18.961: INFO: PersistentVolumeClaim pvc-lvm42 found but phase is Pending instead of Bound. I1105 01:44:20.962] Nov 5 01:44:20.961: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-lvm42] not all in phase Bound within 5m0s I1105 01:44:20.962] [AfterEach] [single-az] I1105 01:44:20.962] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 01:44:20.963] STEP: Collecting events from namespace "azuredisk-3540". I1105 01:44:21.040] STEP: Found 3 events. I1105 01:44:21.041] Nov 5 01:44:21.040: INFO: At 2019-11-05 01:39:19 +0000 UTC - event for pvc-lvm42: {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 01:44:21.041] Nov 5 01:44:21.040: INFO: At 2019-11-05 01:39:19 +0000 UTC - event for pvc-lvm42: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-3540/pvc-lvm42" I1105 01:44:21.042] Nov 5 01:44:21.040: INFO: At 2019-11-05 01:39:19 +0000 UTC - event for pvc-lvm42: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-3540-disk.csi.azure.com-dynamic-sc-xhvsx": 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-5ad5d2fd-ab34-408e-8b14-487779c88eb4' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 01:44:21.122] Nov 5 01:44:21.122: INFO: POD NODE PHASE GRACE CONDITIONS I1105 01:44:21.122] Nov 5 01:44:21.122: INFO: I1105 01:44:21.353] Nov 5 01:44:21.352: INFO: I1105 01:44:21.353] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 01:44:21.437] Nov 5 01:44:21.433: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:2765,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 01:43:49 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 01:43:49 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 01:43:49 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 01:43:49 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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 01:44:21.437] Nov 5 01:44:21.434: INFO: ... skipping 175 lines ... I1105 01:44:42.315] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 01:44:42.315] [single-az] I1105 01:44:42.315] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 01:44:42.315] should create a volume on demand and mount it as readOnly in a pod [It] I1105 01:44:42.315] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:126 I1105 01:44:42.315] I1105 01:44:42.316] Unexpected error: I1105 01:44:42.316] <*errors.errorString | 0xc00075a320>: { I1105 01:44:42.316] s: "PersistentVolumeClaims [pvc-lvm42] not all in phase Bound within 5m0s", I1105 01:44:42.316] } I1105 01:44:42.316] PersistentVolumeClaims [pvc-lvm42] not all in phase Bound within 5m0s I1105 01:44:42.317] occurred I1105 01:44:42.317] ... skipping 214 lines ... I1105 01:45:12.286] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 01:45:12.286] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:36 I1105 01:45:12.286] [env] should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" [It] I1105 01:45:12.286] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:100 I1105 01:45:12.286] I1105 01:45:12.286] Test Panicked I1105 01:45:12.287] runtime error: invalid memory address or nil pointer dereference I1105 01:45:12.287] /usr/local/go/src/runtime/panic.go:82 I1105 01:45:12.287] I1105 01:45:12.287] Full Stack Trace I1105 01:45:12.287] /usr/local/go/src/runtime/panic.go:522 +0x1b5 I1105 01:45:12.288] sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites.(*TestPersistentVolumeClaim).Cleanup(0xc000f20e40) I1105 01:45:12.288] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:313 +0x3b ... skipping 171 lines ... I1105 01:50:02.051] Nov 5 01:50:02.051: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:04.128] Nov 5 01:50:04.128: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:06.206] Nov 5 01:50:06.206: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:08.283] Nov 5 01:50:08.283: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:10.361] Nov 5 01:50:10.361: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:12.439] Nov 5 01:50:12.439: INFO: PersistentVolumeClaim pvc-6lwhr found but phase is Pending instead of Bound. I1105 01:50:14.439] Nov 5 01:50:14.439: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-6lwhr] not all in phase Bound within 5m0s I1105 01:50:14.439] [AfterEach] [single-az] I1105 01:50:14.440] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 01:50:14.440] STEP: Collecting events from namespace "azuredisk-5598". I1105 01:50:14.517] STEP: Found 3 events. I1105 01:50:14.517] Nov 5 01:50:14.517: INFO: At 2019-11-05 01:45:13 +0000 UTC - event for pvc-6lwhr: {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 01:50:14.518] Nov 5 01:50:14.517: INFO: At 2019-11-05 01:45:13 +0000 UTC - event for pvc-6lwhr: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-5598/pvc-6lwhr" I1105 01:50:14.518] Nov 5 01:50:14.517: INFO: At 2019-11-05 01:45:13 +0000 UTC - event for pvc-6lwhr: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-5598-disk.csi.azure.com-dynamic-sc-w6bd4": 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-7849bd5a-21f5-41fe-8fd6-e9779892bcd8' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 01:50:14.594] Nov 5 01:50:14.594: INFO: POD NODE PHASE GRACE CONDITIONS I1105 01:50:14.594] Nov 5 01:50:14.594: INFO: I1105 01:50:14.824] Nov 5 01:50:14.823: INFO: I1105 01:50:14.824] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 01:50:14.904] Nov 5 01:50:14.900: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:3861,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 01:49:50 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 01:49:50 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 01:49:50 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 01:49:50 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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 01:50:14.904] Nov 5 01:50:14.901: INFO: ... skipping 175 lines ... I1105 01:50:35.564] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 01:50:35.564] [single-az] I1105 01:50:35.565] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 01:50:35.565] should create a volume on demand [It] I1105 01:50:35.565] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:78 I1105 01:50:35.565] I1105 01:50:35.565] Unexpected error: I1105 01:50:35.565] <*errors.errorString | 0xc0007206e0>: { I1105 01:50:35.565] s: "PersistentVolumeClaims [pvc-6lwhr] not all in phase Bound within 5m0s", I1105 01:50:35.565] } I1105 01:50:35.566] PersistentVolumeClaims [pvc-6lwhr] not all in phase Bound within 5m0s I1105 01:50:35.566] occurred I1105 01:50:35.566] ... skipping 23 lines ... I1105 01:50:38.186] Nov 5 01:50:38.185: INFO: Waiting up to 5m0s for PersistentVolumeClaims [pvc-wsxcw] to have phase Bound I1105 01:50:38.263] Nov 5 01:50:38.263: INFO: PersistentVolumeClaim pvc-wsxcw found and phase=Bound (77.590805ms) I1105 01:50:38.263] STEP: checking the PVC I1105 01:50:38.340] STEP: validating provisioned PV I1105 01:50:38.417] STEP: checking the PV I1105 01:50:38.417] STEP: deploying the pod I1105 01:50:38.498] STEP: checking that the pods command exits with an error I1105 01:50:38.498] Nov 5 01:50:38.498: INFO: Waiting up to 15m0s for pod "azuredisk-volume-tester-qd9pw" in namespace "azuredisk-8276" to be "Error status code" I1105 01:50:38.579] Nov 5 01:50:38.579: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 81.034932ms I1105 01:50:40.657] Nov 5 01:50:40.657: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.159270747s I1105 01:50:42.735] Nov 5 01:50:42.735: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.236977558s I1105 01:50:44.813] Nov 5 01:50:44.813: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.315079572s I1105 01:50:46.891] Nov 5 01:50:46.891: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.392888984s I1105 01:50:48.969] Nov 5 01:50:48.969: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.470616895s ... skipping 24 lines ... I1105 01:51:40.951] Nov 5 01:51:40.951: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m2.453323559s I1105 01:51:43.029] Nov 5 01:51:43.029: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m4.530798666s I1105 01:51:45.138] Nov 5 01:51:45.137: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m6.639499018s I1105 01:51:47.215] Nov 5 01:51:47.215: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m8.717160526s I1105 01:51:49.293] Nov 5 01:51:49.293: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m10.795096237s I1105 01:51:51.371] Nov 5 01:51:51.371: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Pending", Reason="", readiness=false. Elapsed: 1m12.873193549s I1105 01:51:53.449] Nov 5 01:51:53.449: INFO: Pod "azuredisk-volume-tester-qd9pw": Phase="Failed", Reason="", readiness=false. Elapsed: 1m14.950682957s I1105 01:51:53.449] STEP: Saw pod failure I1105 01:51:53.449] Nov 5 01:51:53.449: INFO: Pod "azuredisk-volume-tester-qd9pw" satisfied condition "Error status code" I1105 01:51:53.449] STEP: checking that pod logs contain expected message I1105 01:51:53.532] Nov 5 01:51:53.531: INFO: deleting Pod "azuredisk-8276"/"azuredisk-volume-tester-qd9pw" I1105 01:51:53.614] Nov 5 01:51:53.614: INFO: Pod azuredisk-volume-tester-qd9pw has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system I1105 01:51:53.614] I1105 01:51:53.615] STEP: Deleting pod azuredisk-volume-tester-qd9pw in namespace azuredisk-8276 I1105 01:51:53.704] STEP: deleting PV "azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q" ... skipping 116 lines ... I1105 02:01:27.803] Nov 5 02:01:27.803: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m34.009823848s) I1105 02:01:32.882] Nov 5 02:01:32.881: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m39.088122643s) I1105 02:01:37.960] Nov 5 02:01:37.959: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m44.166164436s) I1105 02:01:43.038] Nov 5 02:01:43.038: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m49.244726333s) I1105 02:01:48.122] Nov 5 02:01:48.122: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m54.328293269s) I1105 02:01:53.200] Nov 5 02:01:53.199: INFO: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q found and phase=Bound (9m59.40612686s) I1105 02:01:58.200] Nov 5 02:01:58.200: INFO: Unexpected error occurred: PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q still exists within 10m0s I1105 02:01:58.200] [AfterEach] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 02:01:58.201] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:01:58.201] STEP: Collecting events from namespace "azuredisk-8276". I1105 02:01:58.278] STEP: Found 7 events. I1105 02:01:58.279] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:50:38 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {default-scheduler } Scheduled: Successfully assigned azuredisk-8276/azuredisk-volume-tester-qd9pw to k8s-agentpool-15826033-vmss000000 I1105 02:01:58.279] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:50:53 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {attachdetach-controller } FailedAttachVolume: AttachVolume.Attach failed for volume "azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q" : attachment timeout for volume /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/kubetest-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/disks/pre-provisioned-readOnly I1105 02:01:58.279] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:51:24 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q" I1105 02:01:58.279] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:51:50 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {kubelet k8s-agentpool-15826033-vmss000000} Pulling: Pulling image "docker.io/library/busybox:1.29" I1105 02:01:58.280] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:51:50 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {kubelet k8s-agentpool-15826033-vmss000000} Pulled: Successfully pulled image "docker.io/library/busybox:1.29" I1105 02:01:58.280] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:51:52 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {kubelet k8s-agentpool-15826033-vmss000000} Created: Created container volume-tester I1105 02:01:58.280] Nov 5 02:01:58.278: INFO: At 2019-11-05 01:51:52 +0000 UTC - event for azuredisk-volume-tester-qd9pw: {kubelet k8s-agentpool-15826033-vmss000000} Started: Started container volume-tester I1105 02:01:58.355] Nov 5 02:01:58.355: INFO: POD NODE PHASE GRACE CONDITIONS ... skipping 180 lines ... I1105 02:02:19.957] • Failure [704.393 seconds] I1105 02:02:19.957] [azuredisk-csi-e2e] [single-az] Pre-Provisioned I1105 02:02:19.957] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:36 I1105 02:02:19.958] [env] should use a pre-provisioned volume and mount it as readOnly in a pod [It] I1105 02:02:19.958] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/pre_provisioning.go:66 I1105 02:02:19.958] I1105 02:02:19.958] Unexpected error: I1105 02:02:19.958] <*errors.errorString | 0xc00083e510>: { I1105 02:02:19.958] s: "PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q still exists within 10m0s", I1105 02:02:19.959] } I1105 02:02:19.959] PersistentVolume azuredisk-8276-disk.csi.azure.com-preprovsioned-pv-v648q still exists within 10m0s I1105 02:02:19.959] occurred I1105 02:02:19.959] ... skipping 161 lines ... I1105 02:07:09.785] Nov 5 02:07:09.785: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:11.863] Nov 5 02:07:11.863: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:13.943] Nov 5 02:07:13.943: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:16.021] Nov 5 02:07:16.021: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:18.100] Nov 5 02:07:18.100: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:20.178] Nov 5 02:07:20.178: INFO: PersistentVolumeClaim pvc-q9qpz found but phase is Pending instead of Bound. I1105 02:07:22.178] Nov 5 02:07:22.178: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-q9qpz] not all in phase Bound within 5m0s I1105 02:07:22.179] [AfterEach] [multi-az] I1105 02:07:22.179] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:07:22.179] STEP: Collecting events from namespace "azuredisk-104". I1105 02:07:22.257] STEP: Found 3 events. I1105 02:07:22.257] Nov 5 02:07:22.256: INFO: At 2019-11-05 02:02:20 +0000 UTC - event for pvc-q9qpz: {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 02:07:22.257] Nov 5 02:07:22.256: INFO: At 2019-11-05 02:02:20 +0000 UTC - event for pvc-q9qpz: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-104/pvc-q9qpz" I1105 02:07:22.258] Nov 5 02:07:22.256: INFO: At 2019-11-05 02:02:20 +0000 UTC - event for pvc-q9qpz: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-104-disk.csi.azure.com-dynamic-sc-t6xqm": 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-82b77b97-dc12-48e5-bf5d-0c0733f8a1f6' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:07:22.334] Nov 5 02:07:22.334: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:07:22.334] Nov 5 02:07:22.334: INFO: I1105 02:07:22.565] Nov 5 02:07:22.565: INFO: I1105 02:07:22.565] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:07:22.645] Nov 5 02:07:22.642: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:6756,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:06:22 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:06:22 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:06:22 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:06:22 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:07:22.646] Nov 5 02:07:22.643: INFO: ... skipping 175 lines ... I1105 02:07:43.386] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:07:43.387] [multi-az] I1105 02:07:43.387] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 02:07:43.387] should create a volume on demand and mount it as readOnly in a pod [It] I1105 02:07:43.387] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:126 I1105 02:07:43.387] I1105 02:07:43.388] Unexpected error: I1105 02:07:43.388] <*errors.errorString | 0xc000e49b60>: { I1105 02:07:43.388] s: "PersistentVolumeClaims [pvc-q9qpz] not all in phase Bound within 5m0s", I1105 02:07:43.388] } I1105 02:07:43.388] PersistentVolumeClaims [pvc-q9qpz] not all in phase Bound within 5m0s I1105 02:07:43.388] occurred I1105 02:07:43.388] ... skipping 161 lines ... I1105 02:12:33.159] Nov 5 02:12:33.159: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:35.237] Nov 5 02:12:35.236: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:37.315] Nov 5 02:12:37.314: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:39.392] Nov 5 02:12:39.392: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:41.470] Nov 5 02:12:41.470: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:43.548] Nov 5 02:12:43.548: INFO: PersistentVolumeClaim pvc-rkt48 found but phase is Pending instead of Bound. I1105 02:12:45.548] Nov 5 02:12:45.548: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-rkt48] not all in phase Bound within 5m0s I1105 02:12:45.549] [AfterEach] [single-az] I1105 02:12:45.549] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:12:45.549] STEP: Collecting events from namespace "azuredisk-1141". I1105 02:12:45.627] STEP: Found 3 events. I1105 02:12:45.627] Nov 5 02:12:45.627: INFO: At 2019-11-05 02:07:44 +0000 UTC - event for pvc-rkt48: {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 02:12:45.628] Nov 5 02:12:45.627: INFO: At 2019-11-05 02:07:44 +0000 UTC - event for pvc-rkt48: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1141/pvc-rkt48" I1105 02:12:45.628] Nov 5 02:12:45.627: INFO: At 2019-11-05 02:07:44 +0000 UTC - event for pvc-rkt48: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-1141-disk.csi.azure.com-dynamic-sc-7cnrt": 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-a4edd799-8b82-4ed1-849a-6368e074b2d7' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:12:45.705] Nov 5 02:12:45.704: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:12:45.705] Nov 5 02:12:45.704: INFO: I1105 02:12:45.936] Nov 5 02:12:45.936: INFO: I1105 02:12:45.936] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:12:46.017] Nov 5 02:12:46.013: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:7834,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:12:23 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:12:23 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:12:23 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:12:23 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:12:46.017] Nov 5 02:12:46.014: INFO: ... skipping 175 lines ... I1105 02:13:06.694] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:13:06.694] [single-az] I1105 02:13:06.694] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 02:13:06.694] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [It] I1105 02:13:06.694] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:151 I1105 02:13:06.695] I1105 02:13:06.695] Unexpected error: I1105 02:13:06.695] <*errors.errorString | 0xc0001eb860>: { I1105 02:13:06.695] s: "PersistentVolumeClaims [pvc-rkt48] not all in phase Bound within 5m0s", I1105 02:13:06.695] } I1105 02:13:06.696] PersistentVolumeClaims [pvc-rkt48] not all in phase Bound within 5m0s I1105 02:13:06.696] occurred I1105 02:13:06.696] ... skipping 161 lines ... I1105 02:17:56.428] Nov 5 02:17:56.428: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:17:58.506] Nov 5 02:17:58.506: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:18:00.584] Nov 5 02:18:00.583: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:18:02.661] Nov 5 02:18:02.661: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:18:04.738] Nov 5 02:18:04.738: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:18:06.816] Nov 5 02:18:06.816: INFO: PersistentVolumeClaim pvc-zvbnt found but phase is Pending instead of Bound. I1105 02:18:08.816] Nov 5 02:18:08.816: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-zvbnt] not all in phase Bound within 5m0s I1105 02:18:08.817] [AfterEach] [single-az] I1105 02:18:08.817] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:18:08.817] STEP: Collecting events from namespace "azuredisk-8234". I1105 02:18:08.894] STEP: Found 3 events. I1105 02:18:08.894] Nov 5 02:18:08.894: INFO: At 2019-11-05 02:13:07 +0000 UTC - event for pvc-zvbnt: {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 02:18:08.894] Nov 5 02:18:08.894: INFO: At 2019-11-05 02:13:07 +0000 UTC - event for pvc-zvbnt: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8234/pvc-zvbnt" I1105 02:18:08.895] Nov 5 02:18:08.894: INFO: At 2019-11-05 02:13:07 +0000 UTC - event for pvc-zvbnt: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8234-disk.csi.azure.com-dynamic-sc-blrkl": 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-19f49ea0-46d9-4631-9a8c-82314a429761' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:18:08.971] Nov 5 02:18:08.970: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:18:08.971] Nov 5 02:18:08.971: INFO: I1105 02:18:09.200] Nov 5 02:18:09.200: INFO: I1105 02:18:09.200] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:18:09.280] Nov 5 02:18:09.277: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:8737,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:17:24 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:17:24 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:17:24 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:17:24 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:18:09.280] Nov 5 02:18:09.277: INFO: ... skipping 175 lines ... I1105 02:18:29.926] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:18:29.926] [single-az] I1105 02:18:29.926] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 02:18:29.926] should create a raw block volume on demand [It] I1105 02:18:29.927] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:101 I1105 02:18:29.927] I1105 02:18:29.927] Unexpected error: I1105 02:18:29.927] <*errors.errorString | 0xc000f8add0>: { I1105 02:18:29.927] s: "PersistentVolumeClaims [pvc-zvbnt] not all in phase Bound within 5m0s", I1105 02:18:29.927] } I1105 02:18:29.927] PersistentVolumeClaims [pvc-zvbnt] not all in phase Bound within 5m0s I1105 02:18:29.928] occurred I1105 02:18:29.928] ... skipping 161 lines ... I1105 02:23:19.561] Nov 5 02:23:19.561: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:21.639] Nov 5 02:23:21.638: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:23.716] Nov 5 02:23:23.715: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:25.793] Nov 5 02:23:25.793: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:27.871] Nov 5 02:23:27.871: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:29.949] Nov 5 02:23:29.949: INFO: PersistentVolumeClaim pvc-fbpb7 found but phase is Pending instead of Bound. I1105 02:23:31.949] Nov 5 02:23:31.949: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-fbpb7] not all in phase Bound within 5m0s I1105 02:23:31.950] [AfterEach] [single-az] I1105 02:23:31.950] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:23:31.950] STEP: Collecting events from namespace "azuredisk-1124". I1105 02:23:32.027] STEP: Found 3 events. I1105 02:23:32.027] Nov 5 02:23:32.027: INFO: At 2019-11-05 02:18:30 +0000 UTC - event for pvc-fbpb7: {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 02:23:32.028] Nov 5 02:23:32.027: INFO: At 2019-11-05 02:18:30 +0000 UTC - event for pvc-fbpb7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1124/pvc-fbpb7" I1105 02:23:32.028] Nov 5 02:23:32.027: INFO: At 2019-11-05 02:18:30 +0000 UTC - event for pvc-fbpb7: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-1124-disk.csi.azure.com-dynamic-sc-f522k": 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-b594f272-6962-4f9c-b843-41e5759c4632' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:23:32.104] Nov 5 02:23:32.104: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:23:32.104] Nov 5 02:23:32.104: INFO: I1105 02:23:32.334] Nov 5 02:23:32.334: INFO: I1105 02:23:32.334] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:23:32.413] Nov 5 02:23:32.410: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:9812,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:23:25 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:23:25 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:23:25 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:23:25 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:23:32.414] Nov 5 02:23:32.411: INFO: ... skipping 175 lines ... I1105 02:23:53.113] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:23:53.113] [single-az] I1105 02:23:53.113] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 02:23:53.113] should create a deployment object, write and read to it, delete the pod and write and read to it again [It] I1105 02:23:53.113] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:193 I1105 02:23:53.113] I1105 02:23:53.114] Unexpected error: I1105 02:23:53.114] <*errors.errorString | 0xc000936d50>: { I1105 02:23:53.114] s: "PersistentVolumeClaims [pvc-fbpb7] not all in phase Bound within 5m0s", I1105 02:23:53.114] } I1105 02:23:53.114] PersistentVolumeClaims [pvc-fbpb7] not all in phase Bound within 5m0s I1105 02:23:53.114] occurred I1105 02:23:53.114] ... skipping 161 lines ... I1105 02:28:42.888] Nov 5 02:28:42.887: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:44.967] Nov 5 02:28:44.966: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:47.044] Nov 5 02:28:47.044: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:49.128] Nov 5 02:28:49.127: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:51.206] Nov 5 02:28:51.205: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:53.283] Nov 5 02:28:53.283: INFO: PersistentVolumeClaim pvc-4vz8h found but phase is Pending instead of Bound. I1105 02:28:55.284] Nov 5 02:28:55.283: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-4vz8h] not all in phase Bound within 5m0s I1105 02:28:55.284] [AfterEach] [multi-az] I1105 02:28:55.285] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:28:55.285] STEP: Collecting events from namespace "azuredisk-7960". I1105 02:28:55.362] STEP: Found 3 events. I1105 02:28:55.362] Nov 5 02:28:55.362: INFO: At 2019-11-05 02:23:53 +0000 UTC - event for pvc-4vz8h: {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 02:28:55.363] Nov 5 02:28:55.362: INFO: At 2019-11-05 02:23:53 +0000 UTC - event for pvc-4vz8h: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-7960/pvc-4vz8h" I1105 02:28:55.363] Nov 5 02:28:55.362: INFO: At 2019-11-05 02:23:53 +0000 UTC - event for pvc-4vz8h: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-7960-disk.csi.azure.com-dynamic-sc-jcdtm": 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-bab2ead6-6996-424b-8320-48fd7d56fff4' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:28:55.439] Nov 5 02:28:55.439: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:28:55.440] Nov 5 02:28:55.439: INFO: I1105 02:28:55.670] Nov 5 02:28:55.670: INFO: I1105 02:28:55.670] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:28:55.750] Nov 5 02:28:55.747: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:10714,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:28:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:28:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:28:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:28:26 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:28:55.750] Nov 5 02:28:55.747: INFO: ... skipping 175 lines ... I1105 02:29:16.363] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:29:16.364] [multi-az] I1105 02:29:16.364] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 02:29:16.364] [env] should retain PV with reclaimPolicy "Retain" [It] I1105 02:29:16.364] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:240 I1105 02:29:16.364] I1105 02:29:16.365] Unexpected error: I1105 02:29:16.365] <*errors.errorString | 0xc000ca4c30>: { I1105 02:29:16.365] s: "PersistentVolumeClaims [pvc-4vz8h] not all in phase Bound within 5m0s", I1105 02:29:16.365] } I1105 02:29:16.365] PersistentVolumeClaims [pvc-4vz8h] not all in phase Bound within 5m0s I1105 02:29:16.365] occurred I1105 02:29:16.365] ... skipping 161 lines ... I1105 02:34:06.182] Nov 5 02:34:06.181: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:08.259] Nov 5 02:34:08.259: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:10.337] Nov 5 02:34:10.336: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:12.414] Nov 5 02:34:12.414: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:14.492] Nov 5 02:34:14.491: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:16.578] Nov 5 02:34:16.577: INFO: PersistentVolumeClaim pvc-sjl96 found but phase is Pending instead of Bound. I1105 02:34:18.578] Nov 5 02:34:18.578: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-sjl96] not all in phase Bound within 5m0s I1105 02:34:18.578] [AfterEach] [multi-az] I1105 02:34:18.578] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:34:18.578] STEP: Collecting events from namespace "azuredisk-7865". I1105 02:34:18.656] STEP: Found 3 events. I1105 02:34:18.656] Nov 5 02:34:18.656: INFO: At 2019-11-05 02:29:17 +0000 UTC - event for pvc-sjl96: {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 02:34:18.656] Nov 5 02:34:18.656: INFO: At 2019-11-05 02:29:17 +0000 UTC - event for pvc-sjl96: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-7865/pvc-sjl96" I1105 02:34:18.657] Nov 5 02:34:18.656: INFO: At 2019-11-05 02:29:17 +0000 UTC - event for pvc-sjl96: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-7865-disk.csi.azure.com-dynamic-sc-x26jr": 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-07395b67-8969-4afb-b7ec-4fe833ff0e95' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:34:18.740] Nov 5 02:34:18.740: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:34:18.741] Nov 5 02:34:18.740: INFO: I1105 02:34:18.971] Nov 5 02:34:18.971: INFO: I1105 02:34:18.972] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:34:19.051] Nov 5 02:34:19.048: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:11615,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:33:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:33:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:33:26 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:33:26 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:34:19.052] Nov 5 02:34:19.049: INFO: ... skipping 175 lines ... I1105 02:34:37.725] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:34:37.725] [multi-az] I1105 02:34:37.725] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 02:34:37.725] should create a deployment object, write and read to it, delete the pod and write and read to it again [It] I1105 02:34:37.725] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:193 I1105 02:34:37.726] I1105 02:34:37.726] Unexpected error: I1105 02:34:37.726] <*errors.errorString | 0xc0001eaab0>: { I1105 02:34:37.726] s: "PersistentVolumeClaims [pvc-sjl96] not all in phase Bound within 5m0s", I1105 02:34:37.726] } I1105 02:34:37.726] PersistentVolumeClaims [pvc-sjl96] not all in phase Bound within 5m0s I1105 02:34:37.726] occurred I1105 02:34:37.727] ... skipping 161 lines ... I1105 02:39:27.472] Nov 5 02:39:27.472: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:29.550] Nov 5 02:39:29.550: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:31.628] Nov 5 02:39:31.627: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:33.706] Nov 5 02:39:33.705: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:35.784] Nov 5 02:39:35.784: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:37.862] Nov 5 02:39:37.862: INFO: PersistentVolumeClaim pvc-pvkjx found but phase is Pending instead of Bound. I1105 02:39:39.862] Nov 5 02:39:39.862: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-pvkjx] not all in phase Bound within 5m0s I1105 02:39:39.863] [AfterEach] [multi-az] I1105 02:39:39.863] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:39:39.863] STEP: Collecting events from namespace "azuredisk-1320". I1105 02:39:39.946] STEP: Found 3 events. I1105 02:39:39.947] Nov 5 02:39:39.946: INFO: At 2019-11-05 02:34:38 +0000 UTC - event for pvc-pvkjx: {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 02:39:39.947] Nov 5 02:39:39.946: INFO: At 2019-11-05 02:34:38 +0000 UTC - event for pvc-pvkjx: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-1320/pvc-pvkjx" I1105 02:39:39.947] Nov 5 02:39:39.946: INFO: At 2019-11-05 02:34:38 +0000 UTC - event for pvc-pvkjx: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-1320-disk.csi.azure.com-dynamic-sc-hzd8j": 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-a0ed7457-27bb-4e63-90ae-b23b04e1b9de' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:39:40.023] Nov 5 02:39:40.023: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:39:40.024] Nov 5 02:39:40.023: INFO: I1105 02:39:40.254] Nov 5 02:39:40.254: INFO: I1105 02:39:40.255] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:39:40.335] Nov 5 02:39:40.332: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:12700,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:39:27 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:39:27 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:39:27 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:39:27 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:39:40.335] Nov 5 02:39:40.332: INFO: ... skipping 175 lines ... I1105 02:40:00.940] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:40:00.940] [multi-az] I1105 02:40:00.940] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 02:40:00.941] should create multiple PV objects, bind to PVCs and attach all to different pods on the same node [It] I1105 02:40:00.941] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:151 I1105 02:40:00.941] I1105 02:40:00.941] Unexpected error: I1105 02:40:00.941] <*errors.errorString | 0xc000937380>: { I1105 02:40:00.942] s: "PersistentVolumeClaims [pvc-pvkjx] not all in phase Bound within 5m0s", I1105 02:40:00.942] } I1105 02:40:00.942] PersistentVolumeClaims [pvc-pvkjx] not all in phase Bound within 5m0s I1105 02:40:00.942] occurred I1105 02:40:00.942] ... skipping 161 lines ... I1105 02:44:50.783] Nov 5 02:44:50.782: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:44:52.861] Nov 5 02:44:52.860: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:44:54.941] Nov 5 02:44:54.941: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:44:57.019] Nov 5 02:44:57.019: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:44:59.096] Nov 5 02:44:59.096: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:45:01.174] Nov 5 02:45:01.174: INFO: PersistentVolumeClaim pvc-nngqh found but phase is Pending instead of Bound. I1105 02:45:03.175] Nov 5 02:45:03.174: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-nngqh] not all in phase Bound within 5m0s I1105 02:45:03.175] [AfterEach] [single-az] I1105 02:45:03.175] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:45:03.176] STEP: Collecting events from namespace "azuredisk-9787". I1105 02:45:03.253] STEP: Found 3 events. I1105 02:45:03.253] Nov 5 02:45:03.252: INFO: At 2019-11-05 02:40:01 +0000 UTC - event for pvc-nngqh: {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 02:45:03.253] Nov 5 02:45:03.252: INFO: At 2019-11-05 02:40:01 +0000 UTC - event for pvc-nngqh: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-9787/pvc-nngqh" I1105 02:45:03.254] Nov 5 02:45:03.252: INFO: At 2019-11-05 02:40:01 +0000 UTC - event for pvc-nngqh: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-9787-disk.csi.azure.com-dynamic-sc-tp74c": 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-0ef79f1a-4817-47f1-986d-95e6ab0bce77' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:45:03.330] Nov 5 02:45:03.330: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:45:03.330] Nov 5 02:45:03.330: INFO: I1105 02:45:03.561] Nov 5 02:45:03.560: INFO: I1105 02:45:03.561] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:45:03.641] Nov 5 02:45:03.637: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:13603,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:44:28 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:44:28 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:44:28 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:44:28 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:45:03.641] Nov 5 02:45:03.638: INFO: ... skipping 175 lines ... I1105 02:45:24.200] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:45:24.200] [single-az] I1105 02:45:24.201] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 02:45:24.201] [env] should retain PV with reclaimPolicy "Retain" [It] I1105 02:45:24.201] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:240 I1105 02:45:24.201] I1105 02:45:24.201] Unexpected error: I1105 02:45:24.202] <*errors.errorString | 0xc000e48000>: { I1105 02:45:24.202] s: "PersistentVolumeClaims [pvc-nngqh] not all in phase Bound within 5m0s", I1105 02:45:24.202] } I1105 02:45:24.202] PersistentVolumeClaims [pvc-nngqh] not all in phase Bound within 5m0s I1105 02:45:24.202] occurred I1105 02:45:24.202] ... skipping 161 lines ... I1105 02:50:13.920] Nov 5 02:50:13.920: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:15.997] Nov 5 02:50:15.997: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:18.075] Nov 5 02:50:18.075: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:20.152] Nov 5 02:50:20.152: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:22.230] Nov 5 02:50:22.230: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:24.308] Nov 5 02:50:24.307: INFO: PersistentVolumeClaim pvc-6ch89 found but phase is Pending instead of Bound. I1105 02:50:26.308] Nov 5 02:50:26.308: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-6ch89] not all in phase Bound within 5m0s I1105 02:50:26.308] [AfterEach] [single-az] I1105 02:50:26.308] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:50:26.309] STEP: Collecting events from namespace "azuredisk-8754". I1105 02:50:26.386] STEP: Found 3 events. I1105 02:50:26.386] Nov 5 02:50:26.386: INFO: At 2019-11-05 02:45:24 +0000 UTC - event for pvc-6ch89: {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 02:50:26.387] Nov 5 02:50:26.386: INFO: At 2019-11-05 02:45:24 +0000 UTC - event for pvc-6ch89: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8754/pvc-6ch89" I1105 02:50:26.387] Nov 5 02:50:26.386: INFO: At 2019-11-05 02:45:25 +0000 UTC - event for pvc-6ch89: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8754-disk.csi.azure.com-dynamic-sc-rvqkb": 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-5aa7ecda-04df-4896-b774-e1f87555735f' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:50:26.463] Nov 5 02:50:26.463: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:50:26.463] Nov 5 02:50:26.463: INFO: I1105 02:50:26.694] Nov 5 02:50:26.694: INFO: I1105 02:50:26.694] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:50:26.774] Nov 5 02:50:26.771: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:14505,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:49:29 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:49:29 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:49:29 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:49:29 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:50:26.774] Nov 5 02:50:26.771: INFO: ... skipping 175 lines ... I1105 02:50:47.468] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:50:47.468] [single-az] I1105 02:50:47.469] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:36 I1105 02:50:47.469] should delete PV with reclaimPolicy "Delete" [It] I1105 02:50:47.469] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:221 I1105 02:50:47.469] I1105 02:50:47.469] Unexpected error: I1105 02:50:47.469] <*errors.errorString | 0xc0001eaac0>: { I1105 02:50:47.469] s: "PersistentVolumeClaims [pvc-6ch89] not all in phase Bound within 5m0s", I1105 02:50:47.470] } I1105 02:50:47.470] PersistentVolumeClaims [pvc-6ch89] not all in phase Bound within 5m0s I1105 02:50:47.470] occurred I1105 02:50:47.470] ... skipping 161 lines ... I1105 02:55:37.239] Nov 5 02:55:37.239: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:39.317] Nov 5 02:55:39.316: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:41.395] Nov 5 02:55:41.395: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:43.490] Nov 5 02:55:43.472: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:45.550] Nov 5 02:55:45.550: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:47.637] Nov 5 02:55:47.630: INFO: PersistentVolumeClaim pvc-5mr2q found but phase is Pending instead of Bound. I1105 02:55:49.630] Nov 5 02:55:49.630: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-5mr2q] not all in phase Bound within 5m0s I1105 02:55:49.631] [AfterEach] [multi-az] I1105 02:55:49.631] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 02:55:49.631] STEP: Collecting events from namespace "azuredisk-8159". I1105 02:55:49.708] STEP: Found 3 events. I1105 02:55:49.709] Nov 5 02:55:49.708: INFO: At 2019-11-05 02:50:48 +0000 UTC - event for pvc-5mr2q: {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 02:55:49.709] Nov 5 02:55:49.708: INFO: At 2019-11-05 02:50:48 +0000 UTC - event for pvc-5mr2q: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-8159/pvc-5mr2q" I1105 02:55:49.710] Nov 5 02:55:49.708: INFO: At 2019-11-05 02:50:48 +0000 UTC - event for pvc-5mr2q: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-8159-disk.csi.azure.com-dynamic-sc-98mjd": 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-50873950-4b4d-410a-9ab3-101eb7a2c561' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 02:55:49.786] Nov 5 02:55:49.786: INFO: POD NODE PHASE GRACE CONDITIONS I1105 02:55:49.786] Nov 5 02:55:49.786: INFO: I1105 02:55:50.022] Nov 5 02:55:50.022: INFO: I1105 02:55:50.022] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 02:55:50.102] Nov 5 02:55:50.099: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:15583,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 02:55:30 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 02:55:30 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 02:55:30 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 02:55:30 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 02:55:50.102] Nov 5 02:55:50.099: INFO: ... skipping 175 lines ... I1105 02:56:10.761] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 02:56:10.761] [multi-az] I1105 02:56:10.761] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 02:56:10.761] should create a volume on demand [It] I1105 02:56:10.762] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:78 I1105 02:56:10.762] I1105 02:56:10.762] Unexpected error: I1105 02:56:10.762] <*errors.errorString | 0xc00083ebf0>: { I1105 02:56:10.762] s: "PersistentVolumeClaims [pvc-5mr2q] not all in phase Bound within 5m0s", I1105 02:56:10.762] } I1105 02:56:10.762] PersistentVolumeClaims [pvc-5mr2q] not all in phase Bound within 5m0s I1105 02:56:10.763] occurred I1105 02:56:10.763] ... skipping 161 lines ... I1105 03:01:00.657] Nov 5 03:01:00.656: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:02.736] Nov 5 03:01:02.735: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:04.813] Nov 5 03:01:04.813: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:06.898] Nov 5 03:01:06.894: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:08.974] Nov 5 03:01:08.974: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:11.052] Nov 5 03:01:11.051: INFO: PersistentVolumeClaim pvc-vshfr found but phase is Pending instead of Bound. I1105 03:01:13.055] Nov 5 03:01:13.053: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-vshfr] not all in phase Bound within 5m0s I1105 03:01:13.056] [AfterEach] [multi-az] I1105 03:01:13.056] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 03:01:13.056] STEP: Collecting events from namespace "azuredisk-7632". I1105 03:01:13.141] STEP: Found 3 events. I1105 03:01:13.142] Nov 5 03:01:13.141: INFO: At 2019-11-05 02:56:11 +0000 UTC - event for pvc-vshfr: {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 03:01:13.142] Nov 5 03:01:13.141: INFO: At 2019-11-05 02:56:11 +0000 UTC - event for pvc-vshfr: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-7632/pvc-vshfr" I1105 03:01:13.142] Nov 5 03:01:13.141: INFO: At 2019-11-05 02:56:11 +0000 UTC - event for pvc-vshfr: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-7632-disk.csi.azure.com-dynamic-sc-4nmdf": 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-b8b7ef88-1067-43be-b11f-20e225275c8f' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 03:01:13.218] Nov 5 03:01:13.218: INFO: POD NODE PHASE GRACE CONDITIONS I1105 03:01:13.218] Nov 5 03:01:13.218: INFO: I1105 03:01:13.448] Nov 5 03:01:13.448: INFO: I1105 03:01:13.448] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 03:01:13.528] Nov 5 03:01:13.525: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:16484,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 03:00:31 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 03:00:31 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 03:00:31 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 03:00:31 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 03:01:13.528] Nov 5 03:01:13.525: INFO: ... skipping 175 lines ... I1105 03:01:36.792] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 03:01:36.792] [multi-az] I1105 03:01:36.792] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 03:01:36.792] should create a raw block volume on demand [It] I1105 03:01:36.793] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:101 I1105 03:01:36.793] I1105 03:01:36.793] Unexpected error: I1105 03:01:36.793] <*errors.errorString | 0xc0008ffbe0>: { I1105 03:01:36.793] s: "PersistentVolumeClaims [pvc-vshfr] not all in phase Bound within 5m0s", I1105 03:01:36.794] } I1105 03:01:36.794] PersistentVolumeClaims [pvc-vshfr] not all in phase Bound within 5m0s I1105 03:01:36.794] occurred I1105 03:01:36.794] ... skipping 161 lines ... I1105 03:06:26.196] Nov 5 03:06:26.196: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:28.274] Nov 5 03:06:28.274: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:34.083] Nov 5 03:06:30.351: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:34.083] Nov 5 03:06:32.433: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:34.511] Nov 5 03:06:34.511: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:36.589] Nov 5 03:06:36.588: INFO: PersistentVolumeClaim pvc-gtw85 found but phase is Pending instead of Bound. I1105 03:06:38.589] Nov 5 03:06:38.589: INFO: Unexpected error occurred: PersistentVolumeClaims [pvc-gtw85] not all in phase Bound within 5m0s I1105 03:06:38.590] [AfterEach] [multi-az] I1105 03:06:38.590] /go/src/sigs.k8s.io/azuredisk-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:151 I1105 03:06:38.590] STEP: Collecting events from namespace "azuredisk-6855". I1105 03:06:38.667] STEP: Found 3 events. I1105 03:06:38.667] Nov 5 03:06:38.667: INFO: At 2019-11-05 03:01:37 +0000 UTC - event for pvc-gtw85: {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 03:06:38.668] Nov 5 03:06:38.667: INFO: At 2019-11-05 03:01:37 +0000 UTC - event for pvc-gtw85: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } Provisioning: External provisioner is provisioning volume for claim "azuredisk-6855/pvc-gtw85" I1105 03:06:38.669] Nov 5 03:06:38.667: INFO: At 2019-11-05 03:01:37 +0000 UTC - event for pvc-gtw85: {disk.csi.azure.com_csi-azuredisk-controller-6f6587bfc6-8vkfl_1376914b-ff6d-11e9-93ab-ba2bee589b8c } ProvisioningFailed: failed to provision volume with StorageClass "azuredisk-6855-disk.csi.azure.com-dynamic-sc-g682z": 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-818f53fd-e3ad-4de7-9f8b-8e5b9f98b04d' is not supported. The supported zones for location 'eastus2' are '1,2,3'" I1105 03:06:38.744] Nov 5 03:06:38.744: INFO: POD NODE PHASE GRACE CONDITIONS I1105 03:06:38.745] Nov 5 03:06:38.744: INFO: I1105 03:06:38.974] Nov 5 03:06:38.974: INFO: I1105 03:06:38.975] Logging node info for node k8s-agentpool-15826033-vmss000000 I1105 03:06:39.055] Nov 5 03:06:39.052: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:k8s-agentpool-15826033-vmss000000,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/k8s-agentpool-15826033-vmss000000,UID:15fa874e-54ec-42cd-b243-d3baa512150f,ResourceVersion:17562,Generation:0,CreationTimestamp:2019-11-05 01:34:17 +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-4093c0d1-ff68-11e9-b04c-02425d6816e5,kubernetes.azure.com/role: agent,kubernetes.io/arch: amd64,kubernetes.io/hostname: k8s-agentpool-15826033-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-15826033-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-4093c0d1-ff68-11e9-b04c-02425d6816e5/providers/Microsoft.Compute/virtualMachineScaleSets/k8s-agentpool-15826033-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: {{16797044736 0} {<nil>} 16403364Ki 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: {{16010612736 0} {<nil>} 15635364Ki BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{NetworkUnavailable False 2019-11-05 01:34:56 +0000 UTC 2019-11-05 01:34:56 +0000 UTC RouteCreated RouteController created a route} {MemoryPressure False 2019-11-05 03:06:32 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-11-05 03:06:32 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-11-05 03:06:32 +0000 UTC 2019-11-05 01:34:17 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-11-05 03:06:32 +0000 UTC 2019-11-05 01:34:29 +0000 UTC KubeletReady kubelet is posting ready status. AppArmor enabled}],Addresses:[{InternalIP 10.240.0.4} {Hostname k8s-agentpool-15826033-vmss000000}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:afe00792177d49a98f6a44d03d08732d,SystemUUID:4F1777BF-A5C3-004E-81C4-90F0B54C02A0,BootID:13b6a628-ae89-44af-b891-89461030adcb,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} {[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} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/pause-amd64@sha256:59eec8837a4d942cc19a52b8c09ea75121acc38114a2c68b98983ce9356b8610 k8s.gcr.io/pause-amd64:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:nil,},} I1105 03:06:39.055] Nov 5 03:06:39.052: INFO: ... skipping 175 lines ... I1105 03:07:03.942] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:33 I1105 03:07:03.942] [multi-az] I1105 03:07:03.942] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:40 I1105 03:07:03.943] should delete PV with reclaimPolicy "Delete" [It] I1105 03:07:03.943] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/dynamic_provisioning.go:221 I1105 03:07:03.943] I1105 03:07:03.943] Unexpected error: I1105 03:07:03.944] <*errors.errorString | 0xc00073c9a0>: { I1105 03:07:03.944] s: "PersistentVolumeClaims [pvc-gtw85] not all in phase Bound within 5m0s", I1105 03:07:03.944] } I1105 03:07:03.944] PersistentVolumeClaims [pvc-gtw85] not all in phase Bound within 5m0s I1105 03:07:03.945] occurred I1105 03:07:03.945] ... skipping 6 lines ... I1105 03:07:13.859] make[1]: Leaving directory '/go/src/sigs.k8s.io/azuredisk-csi-driver' I1105 03:07:13.859] 2019/11/05 03:07:12 Azure Disk CSI Driver uninstalled I1105 03:07:13.861] I1105 03:07:13.861] I1105 03:07:13.862] Summarizing 16 Failures: I1105 03:07:13.862] I1105 03:07:13.862] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a volume on demand and mount it as readOnly in a pod I1105 03:07:13.863] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.863] I1105 03:07:13.863] [Panic!] [azuredisk-csi-e2e] [single-az] Pre-Provisioned [It] [env] should use a pre-provisioned volume and retain PV with reclaimPolicy "Retain" I1105 03:07:13.863] /usr/local/go/src/runtime/panic.go:82 I1105 03:07:13.864] I1105 03:07:13.864] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a volume on demand I1105 03:07:13.864] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.865] I1105 03:07:13.865] [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 03:07:13.865] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:353 I1105 03:07:13.866] I1105 03:07:13.866] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a volume on demand and mount it as readOnly in a pod I1105 03:07:13.867] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.867] I1105 03:07:13.867] [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 03:07:13.868] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.868] I1105 03:07:13.868] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should create a raw block volume on demand I1105 03:07:13.869] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.869] I1105 03:07:13.869] [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 03:07:13.870] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.870] I1105 03:07:13.870] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] [env] should retain PV with reclaimPolicy "Retain" I1105 03:07:13.871] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.871] I1105 03:07:13.872] [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 03:07:13.872] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.872] I1105 03:07:13.873] [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 03:07:13.873] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.874] I1105 03:07:13.874] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] [env] should retain PV with reclaimPolicy "Retain" I1105 03:07:13.874] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.875] I1105 03:07:13.875] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [single-az] [It] should delete PV with reclaimPolicy "Delete" I1105 03:07:13.875] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.875] I1105 03:07:13.876] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a volume on demand I1105 03:07:13.876] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.876] I1105 03:07:13.876] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should create a raw block volume on demand I1105 03:07:13.877] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.877] I1105 03:07:13.877] [Fail] [azuredisk-csi-e2e] Dynamic Provisioning [multi-az] [It] should delete PV with reclaimPolicy "Delete" I1105 03:07:13.877] /go/src/sigs.k8s.io/azuredisk-csi-driver/test/e2e/testsuites/testsuites.go:278 I1105 03:07:13.877] I1105 03:07:13.878] Ran 16 of 16 Specs in 5424.486 seconds I1105 03:07:13.878] FAIL! -- 0 Passed | 16 Failed | 0 Pending | 0 Skipped I1105 03:07:13.878] --- FAIL: TestE2E (5424.49s) I1105 03:07:13.878] FAIL I1105 03:07:13.878] FAIL sigs.k8s.io/azuredisk-csi-driver/test/e2e 5424.546s W1105 03:07:19.632] make: *** [Makefile:59: e2e-test] Error 1 W1105 03:07:19.632] 2019/11/05 03:07:19 process.go:155: Step 'make e2e-test' finished in 1h31m23.633275644s W1105 03:07:19.632] 2019/11/05 03:07:19 azure.go:912: Skippng DumpClusterLogs due to CCM not being enabled. W1105 03:07:19.633] 2019/11/05 03:07:19 azure.go:906: Deleting resource group: kubetest-4093c0d1-ff68-11e9-b04c-02425d6816e5. W1105 03:15:13.280] 2019/11/05 03:15:13 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml. W1105 03:15:13.282] 2019/11/05 03:15:13 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}" W1105 03:15:14.011] 2019/11/05 03:15:14 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 729.894649ms W1105 03:15:14.011] 2019/11/05 03:15:14 main.go:319: Something went wrong: encountered 1 errors: [error during make e2e-test: exit status 2] W1105 03:15:14.013] Traceback (most recent call last): W1105 03:15:14.013] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module> W1105 03:15:14.014] main(parse_args()) W1105 03:15:14.014] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main W1105 03:15:14.014] mode.start(runner_args) W1105 03:15:14.015] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start W1105 03:15:14.015] check_env(env, self.command, *args) W1105 03:15:14.015] File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env W1105 03:15:14.015] subprocess.check_call(cmd, env=env) W1105 03:15:14.015] File "/usr/lib/python2.7/subprocess.py", line 190, in check_call W1105 03:15:14.015] raise CalledProcessError(retcode, cmd) W1105 03:15:14.016] 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/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 03:15:14.022] Command failed I1105 03:15:14.022] process 685 exited with code 1 after 130.5m E1105 03:15:14.023] FAIL: chewong-pull-azuredisk-csi-driver-e2e-multi-az I1105 03:15:14.023] Call: gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json W1105 03:15:15.011] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com] I1105 03:15:15.044] process 19545 exited with code 0 after 0.0m I1105 03:15:15.044] Call: gcloud config get-value account I1105 03:15:15.298] process 19557 exited with code 0 after 0.0m I1105 03:15:15.298] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com I1105 03:15:15.298] Upload result and artifacts... I1105 03:15:15.299] 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/1191521311436836864 I1105 03:15:15.299] Call: gsutil ls gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191521311436836864/artifacts W1105 03:15:16.484] CommandException: One or more URLs matched no objects. E1105 03:15:16.559] Command failed I1105 03:15:16.559] process 19569 exited with code 1 after 0.0m W1105 03:15:16.560] Remote dir gs://kubernetes-upstream/pr-logs/pull/sigs.k8s.io_azuredisk-csi-driver/180/chewong-pull-azuredisk-csi-driver-e2e-multi-az/1191521311436836864/artifacts not exist yet I1105 03:15:16.560] 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/1191521311436836864/artifacts I1105 03:15:18.072] process 19713 exited with code 0 after 0.0m I1105 03:15:18.072] Call: git rev-parse HEAD I1105 03:15:18.076] process 20242 exited with code 0 after 0.0m ... skipping 21 lines ...