This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 1 failed / 68 succeeded
Started2022-09-22 11:03
Elapsed36m12s
Revisionmaster

Test Failures


EBS CSI Migration Suite External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents 6m9s

go run hack/e2e.go -v --test --test_args='--ginkgo.focus=EBS\sCSI\sMigration\sSuite\sExternal\sStorage\s\[Driver\:\sebs\.csi\.aws\.com\]\s\[Testpattern\:\sDynamic\sPV\s\(default\sfs\)\]\sfsgroupchangepolicy\s\(OnRootMismatch\)\[LinuxOnly\]\,\spod\screated\swith\san\sinitial\sfsgroup\,\svolume\scontents\sownership\schanged\sin\sfirst\spod\,\snew\spod\swith\ssame\sfsgroup\sskips\sownership\schanges\sto\sthe\svolume\scontents$'
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208
Unexpected error:
    <*errors.errorString | 0xc0003a7410>: {
        s: "Timeout occurred",
    }
    Timeout occurred
occurred
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/fsgroupchangepolicy.go:263
				
				Click to see stdout/stderrfrom junit_01.xml

Filter through log files | View test history on testgrid


Show 68 Passed Tests

Show 470 Skipped Tests

Error lines from build-log.txt

... skipping 187 lines ...
|* % . o S o      |
| B * *   + .     |
|o . E *   o      |
| o   . +         |
|  .  .o          |
+----[SHA256]-----+
Error: cluster not found "test-cluster-32322.k8s.local"
###
## Creating cluster test-cluster-32322.k8s.local with /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.yaml (dry run)
#
I0922 11:05:00.891072    5732 create_cluster.go:843] Using SSH public key: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/id_rsa.pub
I0922 11:05:01.726431    5732 new_cluster.go:248] Inferred "aws" cloud provider from zone "us-west-2a"
I0922 11:05:01.726539    5732 new_cluster.go:1102]  Cloud Provider ID = aws
... skipping 76 lines ...
## Validating cluster test-cluster-32322.k8s.local
#
Using cluster from kubectl context: test-cluster-32322.k8s.local

Validating cluster test-cluster-32322.k8s.local

W0922 11:06:10.231112    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:06:20.289888    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:06:30.332209    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:06:40.404115    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:06:53.949394    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:07:07.384929    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0922 11:07:29.137402    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0922 11:07:51.050970    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0922 11:08:12.910294    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0922 11:08:34.612390    5874 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
nodes-us-west-2c	Node	c5.large	1	1	us-west-2c
... skipping 6 lines ...
KIND	NAME						MESSAGE
Machine	i-05adb10bfc527900d				machine "i-05adb10bfc527900d" has not yet joined cluster
Machine	i-081bfd08d2c32887c				machine "i-081bfd08d2c32887c" has not yet joined cluster
Machine	i-09e4cdd2e6119ddd0				machine "i-09e4cdd2e6119ddd0" has not yet joined cluster
Node	ip-172-20-62-44.us-west-2.compute.internal	node "ip-172-20-62-44.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0922 11:08:48.524762    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 7 lines ...
KIND	NAME						MESSAGE
Machine	i-05adb10bfc527900d				machine "i-05adb10bfc527900d" has not yet joined cluster
Machine	i-081bfd08d2c32887c				machine "i-081bfd08d2c32887c" has not yet joined cluster
Machine	i-09e4cdd2e6119ddd0				machine "i-09e4cdd2e6119ddd0" has not yet joined cluster
Node	ip-172-20-62-44.us-west-2.compute.internal	node "ip-172-20-62-44.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0922 11:09:00.539233    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 11 lines ...
Node	ip-172-20-62-44.us-west-2.compute.internal	node "ip-172-20-62-44.us-west-2.compute.internal" of role "master" is not ready
Pod	kube-system/coredns-6d467c5d59-5tzxr		system-cluster-critical pod "coredns-6d467c5d59-5tzxr" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-nrl8d	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-nrl8d" is pending
Pod	kube-system/dns-controller-7c956b559c-qfxh6	system-cluster-critical pod "dns-controller-7c956b559c-qfxh6" is pending
Pod	kube-system/kops-controller-zzvh8		system-cluster-critical pod "kops-controller-zzvh8" is pending

Validation Failed
W0922 11:09:12.946055    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 14 lines ...
Pod	kube-system/coredns-6d467c5d59-5tzxr					system-cluster-critical pod "coredns-6d467c5d59-5tzxr" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-nrl8d				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-nrl8d" is pending
Pod	kube-system/dns-controller-7c956b559c-qfxh6				system-cluster-critical pod "dns-controller-7c956b559c-qfxh6" is pending
Pod	kube-system/kops-controller-zzvh8					system-cluster-critical pod "kops-controller-zzvh8" is pending
Pod	kube-system/kube-proxy-ip-172-20-62-44.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-62-44.us-west-2.compute.internal" is pending

Validation Failed
W0922 11:09:25.246839    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 12 lines ...
Node	ip-172-20-62-44.us-west-2.compute.internal				master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-62-44.us-west-2.compute.internal				master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-6d467c5d59-5tzxr					system-cluster-critical pod "coredns-6d467c5d59-5tzxr" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-nrl8d				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-nrl8d" is pending
Pod	kube-system/kube-apiserver-ip-172-20-62-44.us-west-2.compute.internal	system-cluster-critical pod "kube-apiserver-ip-172-20-62-44.us-west-2.compute.internal" is pending

Validation Failed
W0922 11:09:37.217596    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 14 lines ...
Node	ip-172-20-72-139.us-west-2.compute.internal				node "ip-172-20-72-139.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-99-50.us-west-2.compute.internal				node "ip-172-20-99-50.us-west-2.compute.internal" of role "node" is not ready
Pod	kube-system/coredns-6d467c5d59-5tzxr					system-cluster-critical pod "coredns-6d467c5d59-5tzxr" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-nrl8d				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-nrl8d" is pending
Pod	kube-system/kube-proxy-ip-172-20-72-139.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-72-139.us-west-2.compute.internal" is pending

Validation Failed
W0922 11:09:49.459682    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 9 lines ...
VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-62-44.us-west-2.compute.internal	master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-62-44.us-west-2.compute.internal	master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-6d467c5d59-4znkl		system-cluster-critical pod "coredns-6d467c5d59-4znkl" is not ready (coredns)

Validation Failed
W0922 11:10:01.891248    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 7 lines ...
ip-172-20-99-50.us-west-2.compute.internal	node	True

VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-62-44.us-west-2.compute.internal	master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-scheduler pod

Validation Failed
W0922 11:10:14.032832    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 8 lines ...

VALIDATION ERRORS
KIND	NAME									MESSAGE
Node	ip-172-20-62-44.us-west-2.compute.internal				master "ip-172-20-62-44.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/kube-scheduler-ip-172-20-62-44.us-west-2.compute.internal	system-cluster-critical pod "kube-scheduler-ip-172-20-62-44.us-west-2.compute.internal" is pending

Validation Failed
W0922 11:10:26.135149    5874 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 190 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 224 lines ...

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (immediate binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/topology.go:192

[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:12:33.338: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/topology.go:192
Sep 22 11:12:33.717: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2a]
Sep 22 11:12:33.717: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2b]
Sep 22 11:12:33.718: INFO: Creating storage class object and pvc object for driver - sc: &StorageClass{ObjectMeta:{topology-85-e2e-sczcrqh      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:nil,MountOptions:[],AllowVolumeExpansion:nil,VolumeBindingMode:*Immediate,AllowedTopologies:[]TopologySelectorTerm{{[{topology.ebs.csi.aws.com/zone [us-west-2b]}]},},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- topology-85    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*topology-85-e2e-sczcrqh,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating sc
STEP: Creating pvc
... skipping 12 lines ...
Sep 22 11:12:34.304: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
STEP: Destroying namespace "topology-85" for this suite.

•S
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:12:31.532: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename provisioning
Sep 22 11:12:31.977: INFO: No PodSecurityPolicies found; assuming PodSecurityPolicy is disabled.
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278
Sep 22 11:12:32.107: INFO: Creating resource for dynamic PV
Sep 22 11:12:32.107: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-1972-e2e-sc9dwtj
STEP: creating a claim
Sep 22 11:12:32.174: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-24hg
STEP: Checking for subpath error in container status
Sep 22 11:12:50.515: INFO: Deleting pod "pod-subpath-test-dynamicpv-24hg" in namespace "provisioning-1972"
Sep 22 11:12:50.585: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-24hg" to be fully deleted
STEP: Deleting pod
Sep 22 11:12:54.717: INFO: Deleting pod "pod-subpath-test-dynamicpv-24hg" in namespace "provisioning-1972"
STEP: Deleting pvc
Sep 22 11:12:54.914: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.com8hzfn"
... skipping 10 lines ...

• [SLOW TEST:33.919 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278
------------------------------
S
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
... skipping 77 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 813 lines ...

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:121
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297

[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:14:27.280: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297
Sep 22 11:14:27.612: INFO: Creating resource for dynamic PV
Sep 22 11:14:27.613: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-1908-e2e-sc6822s
STEP: creating a claim
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep 22 11:14:34.080: INFO: Deleting pod "pod-afd21a88-3374-41d3-9189-500a973b0a07" in namespace "volumemode-1908"
Sep 22 11:14:34.147: INFO: Wait up to 5m0s for pod "pod-afd21a88-3374-41d3-9189-500a973b0a07" to be fully deleted
STEP: Deleting pvc
Sep 22 11:14:44.415: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.comfxmkm"
Sep 22 11:14:44.482: INFO: Waiting up to 5m0s for PersistentVolume pvc-d8b95c39-5354-4365-88ba-fdc0bbab8d56 to get deleted
Sep 22 11:14:44.548: INFO: PersistentVolume pvc-d8b95c39-5354-4365-88ba-fdc0bbab8d56 found and phase=Released (65.717381ms)
... skipping 7 lines ...

• [SLOW TEST:22.542 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
Sep 22 11:14:49.823: INFO: Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
... skipping 65 lines ...
Sep 22 11:12:32.652: INFO: Creating resource for dynamic PV
Sep 22 11:12:32.652: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-5797-e2e-sc7j6g8
STEP: creating a claim
Sep 22 11:12:32.717: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
Sep 22 11:12:32.910: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-4hxsn" in namespace "snapshotting-5797" to be "Succeeded or Failed"
Sep 22 11:12:32.973: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 62.656386ms
Sep 22 11:12:35.039: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.128490213s
Sep 22 11:12:37.104: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.193450205s
Sep 22 11:12:39.169: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.258675731s
Sep 22 11:12:41.237: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.326906769s
Sep 22 11:12:43.300: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.390241498s
Sep 22 11:12:45.365: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.45533948s
Sep 22 11:12:47.430: INFO: Pod "pvc-snapshottable-tester-4hxsn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.519488432s
STEP: Saw pod success
Sep 22 11:12:47.430: INFO: Pod "pvc-snapshottable-tester-4hxsn" satisfied condition "Succeeded or Failed"
Sep 22 11:12:47.582: INFO: Pod pvc-snapshottable-tester-4hxsn has the following logs: 
Sep 22 11:12:47.582: INFO: Deleting pod "pvc-snapshottable-tester-4hxsn" in namespace "snapshotting-5797"
Sep 22 11:12:47.650: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-4hxsn" to be fully deleted
Sep 22 11:12:47.713: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [ebs.csi.aws.commdxrk] to have phase Bound
Sep 22 11:12:47.776: INFO: PersistentVolumeClaim ebs.csi.aws.commdxrk found and phase=Bound (62.790072ms)
STEP: [init] checking the claim
... skipping 67 lines ...
[It] should check snapshot fields, check restore correctly works after modifying source data, check deletion
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:250
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep 22 11:13:59.509: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-fbbbj" in namespace "snapshotting-5797" to be "Succeeded or Failed"
Sep 22 11:13:59.571: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 62.249381ms
Sep 22 11:14:01.640: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13082411s
Sep 22 11:14:03.767: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 4.258069386s
Sep 22 11:14:05.831: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 6.321570893s
Sep 22 11:14:07.895: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 8.38566493s
Sep 22 11:14:09.958: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Pending", Reason="", readiness=false. Elapsed: 10.449197896s
Sep 22 11:14:12.023: INFO: Pod "pvc-snapshottable-data-tester-fbbbj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.51386307s
STEP: Saw pod success
Sep 22 11:14:12.023: INFO: Pod "pvc-snapshottable-data-tester-fbbbj" satisfied condition "Succeeded or Failed"
Sep 22 11:14:12.152: INFO: Pod pvc-snapshottable-data-tester-fbbbj has the following logs: 
Sep 22 11:14:12.152: INFO: Deleting pod "pvc-snapshottable-data-tester-fbbbj" in namespace "snapshotting-5797"
Sep 22 11:14:12.220: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-fbbbj" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the claim
Sep 22 11:14:26.541: INFO: Running '/usr/local/bin/kubectl --server=https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com --kubeconfig=/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig --namespace=snapshotting-5797 exec restored-pvc-tester-trhps --namespace=snapshotting-5797 -- cat /mnt/test/data'
... skipping 34 lines ...
Sep 22 11:14:52.174: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:53.238: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:54.302: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:55.366: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:56.430: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:57.494: INFO: volumesnapshotcontents pre-provisioned-snapcontent-1ba3bcf7-4335-4101-b887-932f5aafc0b7 has been found and is not deleted
Sep 22 11:14:58.494: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:228
Sep 22 11:14:58.559: INFO: Pod restored-pvc-tester-trhps has the following logs: 
Sep 22 11:14:58.559: INFO: Deleting pod "restored-pvc-tester-trhps" in namespace "snapshotting-5797"
Sep 22 11:14:58.621: INFO: Wait up to 5m0s for pod "restored-pvc-tester-trhps" to be fully deleted
Sep 22 11:15:00.749: INFO: deleting claim "snapshotting-5797"/"pvc-qkpg5"
... skipping 141 lines ...
Sep 22 11:15:09.213: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-1935-e2e-sc2lpb7
STEP: creating a claim
Sep 22 11:15:09.277: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-tg4v
STEP: Creating a pod to test multi_subpath
Sep 22 11:15:09.471: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-tg4v" in namespace "provisioning-1935" to be "Succeeded or Failed"
Sep 22 11:15:09.536: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Pending", Reason="", readiness=false. Elapsed: 64.746876ms
Sep 22 11:15:11.605: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Pending", Reason="", readiness=false. Elapsed: 2.133642067s
Sep 22 11:15:13.670: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Pending", Reason="", readiness=false. Elapsed: 4.198517471s
Sep 22 11:15:15.734: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Pending", Reason="", readiness=false. Elapsed: 6.262559182s
Sep 22 11:15:17.797: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Pending", Reason="", readiness=false. Elapsed: 8.326195328s
Sep 22 11:15:19.861: INFO: Pod "pod-subpath-test-dynamicpv-tg4v": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.389910892s
STEP: Saw pod success
Sep 22 11:15:19.861: INFO: Pod "pod-subpath-test-dynamicpv-tg4v" satisfied condition "Succeeded or Failed"
Sep 22 11:15:19.924: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-tg4v container test-container-subpath-dynamicpv-tg4v: <nil>
STEP: delete the pod
Sep 22 11:15:20.061: INFO: Waiting for pod pod-subpath-test-dynamicpv-tg4v to disappear
Sep 22 11:15:20.124: INFO: Pod pod-subpath-test-dynamicpv-tg4v no longer exists
STEP: Deleting pod
Sep 22 11:15:20.124: INFO: Deleting pod "pod-subpath-test-dynamicpv-tg4v" in namespace "provisioning-1935"
... skipping 60 lines ...
Sep 22 11:15:16.098: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-9224-e2e-scfvvmk
STEP: creating a claim
Sep 22 11:15:16.164: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-nrrr
STEP: Creating a pod to test exec-volume-test
Sep 22 11:15:16.364: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-nrrr" in namespace "volume-9224" to be "Succeeded or Failed"
Sep 22 11:15:16.430: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 65.874441ms
Sep 22 11:15:18.497: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132328764s
Sep 22 11:15:20.562: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197902479s
Sep 22 11:15:22.631: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.266838142s
Sep 22 11:15:24.697: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.332771465s
Sep 22 11:15:26.764: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Pending", Reason="", readiness=false. Elapsed: 10.399487672s
Sep 22 11:15:28.830: INFO: Pod "exec-volume-test-dynamicpv-nrrr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.465889597s
STEP: Saw pod success
Sep 22 11:15:28.830: INFO: Pod "exec-volume-test-dynamicpv-nrrr" satisfied condition "Succeeded or Failed"
Sep 22 11:15:28.898: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod exec-volume-test-dynamicpv-nrrr container exec-container-dynamicpv-nrrr: <nil>
STEP: delete the pod
Sep 22 11:15:29.036: INFO: Waiting for pod exec-volume-test-dynamicpv-nrrr to disappear
Sep 22 11:15:29.101: INFO: Pod exec-volume-test-dynamicpv-nrrr no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-nrrr
Sep 22 11:15:29.101: INFO: Deleting pod "exec-volume-test-dynamicpv-nrrr" in namespace "volume-9224"
... skipping 171 lines ...
Sep 22 11:15:36.170: INFO: Creating resource for dynamic PV
Sep 22 11:15:36.170: INFO: Using claimSize:1Gi, test suite supported size:{ 1Gi}, driver(ebs.csi.aws.com) supported size:{ 1Gi} 
STEP: creating a StorageClass volume-expand-859-e2e-sc4hht5
STEP: creating a claim
STEP: Expanding non-expandable pvc
Sep 22 11:15:36.364: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep 22 11:15:36.492: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:38.620: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:40.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:42.624: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:44.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:46.620: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:48.621: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:50.621: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:52.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:54.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:56.621: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:15:58.621: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:16:00.620: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:16:02.626: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:16:04.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:16:06.622: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-859-e2e-sc4hht5",
  	... // 2 identical fields
  }

Sep 22 11:16:06.749: INFO: Error updating pvc ebs.csi.aws.comrbn56: PersistentVolumeClaim "ebs.csi.aws.comrbn56" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 335 lines ...
Sep 22 11:16:27.540: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6397-e2e-scsn79w
STEP: creating a claim
Sep 22 11:16:27.607: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-t9dv
STEP: Creating a pod to test subpath
Sep 22 11:16:27.810: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-t9dv" in namespace "provisioning-6397" to be "Succeeded or Failed"
Sep 22 11:16:27.876: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Pending", Reason="", readiness=false. Elapsed: 66.109296ms
Sep 22 11:16:29.942: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13242682s
Sep 22 11:16:32.009: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199101383s
Sep 22 11:16:34.075: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.265419489s
Sep 22 11:16:36.143: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.333119211s
Sep 22 11:16:38.210: INFO: Pod "pod-subpath-test-dynamicpv-t9dv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.399837715s
STEP: Saw pod success
Sep 22 11:16:38.210: INFO: Pod "pod-subpath-test-dynamicpv-t9dv" satisfied condition "Succeeded or Failed"
Sep 22 11:16:38.276: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-t9dv container test-container-volume-dynamicpv-t9dv: <nil>
STEP: delete the pod
Sep 22 11:16:38.418: INFO: Waiting for pod pod-subpath-test-dynamicpv-t9dv to disappear
Sep 22 11:16:38.489: INFO: Pod pod-subpath-test-dynamicpv-t9dv no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-t9dv
Sep 22 11:16:38.489: INFO: Deleting pod "pod-subpath-test-dynamicpv-t9dv" in namespace "provisioning-6397"
... skipping 21 lines ...
    should support non-existent path
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:194
------------------------------
S
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:16:35.514: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267
Sep 22 11:16:35.844: INFO: Creating resource for dynamic PV
Sep 22 11:16:35.844: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6373-e2e-schnqzx
STEP: creating a claim
Sep 22 11:16:35.910: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-658w
STEP: Checking for subpath error in container status
Sep 22 11:16:50.245: INFO: Deleting pod "pod-subpath-test-dynamicpv-658w" in namespace "provisioning-6373"
Sep 22 11:16:50.312: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-658w" to be fully deleted
STEP: Deleting pod
Sep 22 11:16:54.445: INFO: Deleting pod "pod-subpath-test-dynamicpv-658w" in namespace "provisioning-6373"
STEP: Deleting pvc
Sep 22 11:16:54.642: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.commlqjl"
... skipping 10 lines ...

• [SLOW TEST:29.602 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
Sep 22 11:17:05.118: INFO: Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 30 lines ...
Sep 22 11:16:50.342: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6317-e2e-scbptcz
STEP: creating a claim
Sep 22 11:16:50.406: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-hlb4
STEP: Creating a pod to test subpath
Sep 22 11:16:50.599: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-hlb4" in namespace "provisioning-6317" to be "Succeeded or Failed"
Sep 22 11:16:50.662: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 63.812962ms
Sep 22 11:16:52.726: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127734596s
Sep 22 11:16:54.792: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.193030025s
Sep 22 11:16:56.855: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.256738198s
Sep 22 11:16:58.919: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.320646443s
Sep 22 11:17:00.987: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.388641358s
... skipping 2 lines ...
Sep 22 11:17:07.193: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 16.594085583s
Sep 22 11:17:09.261: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 18.66231304s
Sep 22 11:17:11.324: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 20.725521444s
Sep 22 11:17:13.389: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Pending", Reason="", readiness=false. Elapsed: 22.790278214s
Sep 22 11:17:15.453: INFO: Pod "pod-subpath-test-dynamicpv-hlb4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 24.854075427s
STEP: Saw pod success
Sep 22 11:17:15.453: INFO: Pod "pod-subpath-test-dynamicpv-hlb4" satisfied condition "Succeeded or Failed"
Sep 22 11:17:15.515: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-hlb4 container test-container-subpath-dynamicpv-hlb4: <nil>
STEP: delete the pod
Sep 22 11:17:15.649: INFO: Waiting for pod pod-subpath-test-dynamicpv-hlb4 to disappear
Sep 22 11:17:15.711: INFO: Pod pod-subpath-test-dynamicpv-hlb4 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-hlb4
Sep 22 11:17:15.711: INFO: Deleting pod "pod-subpath-test-dynamicpv-hlb4" in namespace "provisioning-6317"
... skipping 78 lines ...
Sep 22 11:16:54.644: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-7266-e2e-sc6x8nt
STEP: creating a claim
Sep 22 11:16:54.716: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-nrld
STEP: Creating a pod to test subpath
Sep 22 11:16:54.928: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-nrld" in namespace "provisioning-7266" to be "Succeeded or Failed"
Sep 22 11:16:54.995: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 66.232426ms
Sep 22 11:16:57.063: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134599654s
Sep 22 11:16:59.130: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201794539s
Sep 22 11:17:01.198: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 6.269456602s
Sep 22 11:17:03.265: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 8.336166425s
Sep 22 11:17:05.332: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 10.403392938s
Sep 22 11:17:07.399: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 12.470810638s
Sep 22 11:17:09.469: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 14.540738309s
Sep 22 11:17:11.536: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.607944971s
STEP: Saw pod success
Sep 22 11:17:11.536: INFO: Pod "pod-subpath-test-dynamicpv-nrld" satisfied condition "Succeeded or Failed"
Sep 22 11:17:11.602: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-nrld container test-container-subpath-dynamicpv-nrld: <nil>
STEP: delete the pod
Sep 22 11:17:11.741: INFO: Waiting for pod pod-subpath-test-dynamicpv-nrld to disappear
Sep 22 11:17:11.806: INFO: Pod pod-subpath-test-dynamicpv-nrld no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-nrld
Sep 22 11:17:11.807: INFO: Deleting pod "pod-subpath-test-dynamicpv-nrld" in namespace "provisioning-7266"
STEP: Creating pod pod-subpath-test-dynamicpv-nrld
STEP: Creating a pod to test subpath
Sep 22 11:17:11.940: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-nrld" in namespace "provisioning-7266" to be "Succeeded or Failed"
Sep 22 11:17:12.006: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 65.897379ms
Sep 22 11:17:14.078: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Pending", Reason="", readiness=false. Elapsed: 2.138531215s
Sep 22 11:17:16.146: INFO: Pod "pod-subpath-test-dynamicpv-nrld": Phase="Succeeded", Reason="", readiness=false. Elapsed: 4.206197232s
STEP: Saw pod success
Sep 22 11:17:16.146: INFO: Pod "pod-subpath-test-dynamicpv-nrld" satisfied condition "Succeeded or Failed"
Sep 22 11:17:16.213: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-nrld container test-container-subpath-dynamicpv-nrld: <nil>
STEP: delete the pod
Sep 22 11:17:16.354: INFO: Waiting for pod pod-subpath-test-dynamicpv-nrld to disappear
Sep 22 11:17:16.419: INFO: Pod pod-subpath-test-dynamicpv-nrld no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-nrld
Sep 22 11:17:16.420: INFO: Deleting pod "pod-subpath-test-dynamicpv-nrld" in namespace "provisioning-7266"
... skipping 92 lines ...
Sep 22 11:17:05.448: INFO: In creating storage class object and pvc objects for driver - sc: &StorageClass{ObjectMeta:{provisioning-1551-e2e-scwh77w      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:nil,MountOptions:[],AllowVolumeExpansion:nil,VolumeBindingMode:*WaitForFirstConsumer,AllowedTopologies:[]TopologySelectorTerm{},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-1551    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-1551-e2e-scwh77w,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}, src-pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-1551    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-1551-e2e-scwh77w,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating a StorageClass
STEP: creating claim=&PersistentVolumeClaim{ObjectMeta:{ pvc- provisioning-1551    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-1551-e2e-scwh77w,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: creating a pod referring to the class=&StorageClass{ObjectMeta:{provisioning-1551-e2e-scwh77w    90d3f0ae-37c0-446f-a572-a813f61af599 3897 0 2022-09-22 11:17:05 +0000 UTC <nil> <nil> map[] map[] [] []  [{e2e-kubernetes.test Update storage.k8s.io/v1 2022-09-22 11:17:05 +0000 UTC FieldsV1 {"f:mountOptions":{},"f:provisioner":{},"f:reclaimPolicy":{},"f:volumeBindingMode":{}} }]},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:*Delete,MountOptions:[dirsync],AllowVolumeExpansion:nil,VolumeBindingMode:*WaitForFirstConsumer,AllowedTopologies:[]TopologySelectorTerm{},} claim=&PersistentVolumeClaim{ObjectMeta:{pvc-zfsj9 pvc- provisioning-1551  69e14a43-653b-47e2-8a49-477f6db90b40 3898 0 2022-09-22 11:17:05 +0000 UTC <nil> <nil> map[] map[] [] [kubernetes.io/pvc-protection]  [{e2e-kubernetes.test Update v1 2022-09-22 11:17:05 +0000 UTC FieldsV1 {"f:metadata":{"f:generateName":{}},"f:spec":{"f:accessModes":{},"f:resources":{"f:requests":{".":{},"f:storage":{}}},"f:storageClassName":{},"f:volumeMode":{}},"f:status":{"f:phase":{}}} }]},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*provisioning-1551-e2e-scwh77w,VolumeMode:*Filesystem,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:Pending,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Deleting pod pod-cf82fb38-4030-4124-8601-90c56da53225 in namespace provisioning-1551
STEP: checking the created volume is writable on node {Name: Selector:map[] Affinity:nil}
Sep 22 11:17:20.179: INFO: Waiting up to 15m0s for pod "pvc-volume-tester-writer-4cqjh" in namespace "provisioning-1551" to be "Succeeded or Failed"
Sep 22 11:17:20.246: INFO: Pod "pvc-volume-tester-writer-4cqjh": Phase="Pending", Reason="", readiness=false. Elapsed: 66.363453ms
Sep 22 11:17:22.311: INFO: Pod "pvc-volume-tester-writer-4cqjh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.131869945s
STEP: Saw pod success
Sep 22 11:17:22.311: INFO: Pod "pvc-volume-tester-writer-4cqjh" satisfied condition "Succeeded or Failed"
Sep 22 11:17:22.444: INFO: Pod pvc-volume-tester-writer-4cqjh has the following logs: 
Sep 22 11:17:22.444: INFO: Deleting pod "pvc-volume-tester-writer-4cqjh" in namespace "provisioning-1551"
Sep 22 11:17:22.515: INFO: Wait up to 5m0s for pod "pvc-volume-tester-writer-4cqjh" to be fully deleted
STEP: checking the created volume has the correct mount options, is readable and retains data on the same node "ip-172-20-99-50.us-west-2.compute.internal"
Sep 22 11:17:22.781: INFO: Waiting up to 15m0s for pod "pvc-volume-tester-reader-dp6h6" in namespace "provisioning-1551" to be "Succeeded or Failed"
Sep 22 11:17:22.846: INFO: Pod "pvc-volume-tester-reader-dp6h6": Phase="Pending", Reason="", readiness=false. Elapsed: 64.998149ms
Sep 22 11:17:24.913: INFO: Pod "pvc-volume-tester-reader-dp6h6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 2.131650564s
STEP: Saw pod success
Sep 22 11:17:24.913: INFO: Pod "pvc-volume-tester-reader-dp6h6" satisfied condition "Succeeded or Failed"
Sep 22 11:17:25.050: INFO: Pod pvc-volume-tester-reader-dp6h6 has the following logs: hello world

Sep 22 11:17:25.050: INFO: Deleting pod "pvc-volume-tester-reader-dp6h6" in namespace "provisioning-1551"
Sep 22 11:17:25.122: INFO: Wait up to 5m0s for pod "pvc-volume-tester-reader-dp6h6" to be fully deleted
Sep 22 11:17:25.187: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-zfsj9] to have phase Bound
Sep 22 11:17:25.252: INFO: PersistentVolumeClaim pvc-zfsj9 found and phase=Bound (64.920459ms)
... skipping 96 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
SSS
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:17:32.740: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240
Sep 22 11:17:33.085: INFO: Creating resource for dynamic PV
Sep 22 11:17:33.086: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2499-e2e-sc9n54b
STEP: creating a claim
Sep 22 11:17:33.153: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-rskb
STEP: Checking for subpath error in container status
Sep 22 11:17:47.491: INFO: Deleting pod "pod-subpath-test-dynamicpv-rskb" in namespace "provisioning-2499"
Sep 22 11:17:47.559: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-rskb" to be fully deleted
STEP: Deleting pod
Sep 22 11:17:53.692: INFO: Deleting pod "pod-subpath-test-dynamicpv-rskb" in namespace "provisioning-2499"
STEP: Deleting pvc
Sep 22 11:17:53.889: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.combddql"
... skipping 10 lines ...

• [SLOW TEST:31.639 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  
  should check snapshot fields, check restore correctly works after modifying source data, check deletion
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:250

... skipping 10 lines ...
Sep 22 11:16:01.625: INFO: Creating resource for dynamic PV
Sep 22 11:16:01.625: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-3553-e2e-scf7c6k
STEP: creating a claim
Sep 22 11:16:01.690: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
Sep 22 11:16:01.888: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-s49bf" in namespace "snapshotting-3553" to be "Succeeded or Failed"
Sep 22 11:16:01.955: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 66.266195ms
Sep 22 11:16:04.019: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13104233s
Sep 22 11:16:06.085: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.196123308s
Sep 22 11:16:08.149: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.260590024s
Sep 22 11:16:10.213: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.324842675s
Sep 22 11:16:12.283: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.394267251s
Sep 22 11:16:14.346: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 12.457925361s
Sep 22 11:16:16.411: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 14.522108295s
Sep 22 11:16:18.475: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 16.586446153s
Sep 22 11:16:20.539: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 18.650650593s
Sep 22 11:16:22.603: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Pending", Reason="", readiness=false. Elapsed: 20.714488651s
Sep 22 11:16:24.670: INFO: Pod "pvc-snapshottable-tester-s49bf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.781944971s
STEP: Saw pod success
Sep 22 11:16:24.670: INFO: Pod "pvc-snapshottable-tester-s49bf" satisfied condition "Succeeded or Failed"
Sep 22 11:16:24.799: INFO: Pod pvc-snapshottable-tester-s49bf has the following logs: 
Sep 22 11:16:24.799: INFO: Deleting pod "pvc-snapshottable-tester-s49bf" in namespace "snapshotting-3553"
Sep 22 11:16:24.874: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-s49bf" to be fully deleted
Sep 22 11:16:24.937: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [ebs.csi.aws.comtwfzc] to have phase Bound
Sep 22 11:16:25.001: INFO: PersistentVolumeClaim ebs.csi.aws.comtwfzc found and phase=Bound (63.509032ms)
STEP: [init] checking the claim
... skipping 45 lines ...
[It] should check snapshot fields, check restore correctly works after modifying source data, check deletion
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:250
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep 22 11:17:31.867: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-vhsg2" in namespace "snapshotting-3553" to be "Succeeded or Failed"
Sep 22 11:17:31.934: INFO: Pod "pvc-snapshottable-data-tester-vhsg2": Phase="Pending", Reason="", readiness=false. Elapsed: 67.236384ms
Sep 22 11:17:34.004: INFO: Pod "pvc-snapshottable-data-tester-vhsg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.136459221s
Sep 22 11:17:36.068: INFO: Pod "pvc-snapshottable-data-tester-vhsg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.200942912s
Sep 22 11:17:38.132: INFO: Pod "pvc-snapshottable-data-tester-vhsg2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.265269802s
STEP: Saw pod success
Sep 22 11:17:38.132: INFO: Pod "pvc-snapshottable-data-tester-vhsg2" satisfied condition "Succeeded or Failed"
Sep 22 11:17:38.261: INFO: Pod pvc-snapshottable-data-tester-vhsg2 has the following logs: 
Sep 22 11:17:38.261: INFO: Deleting pod "pvc-snapshottable-data-tester-vhsg2" in namespace "snapshotting-3553"
Sep 22 11:17:38.332: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-vhsg2" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the claim
Sep 22 11:17:48.655: INFO: Running '/usr/local/bin/kubectl --server=https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com --kubeconfig=/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig --namespace=snapshotting-3553 exec restored-pvc-tester-rcvcs --namespace=snapshotting-3553 -- cat /mnt/test/data'
... skipping 177 lines ...
Sep 22 11:17:51.493: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6958-e2e-scnjztl
STEP: creating a claim
Sep 22 11:17:51.560: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-7ttz
STEP: Creating a pod to test atomic-volume-subpath
Sep 22 11:17:51.769: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-7ttz" in namespace "provisioning-6958" to be "Succeeded or Failed"
Sep 22 11:17:51.834: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 65.156409ms
Sep 22 11:17:53.903: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134608885s
Sep 22 11:17:55.968: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199879577s
Sep 22 11:17:58.035: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 6.26631275s
Sep 22 11:18:00.102: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 8.333004528s
Sep 22 11:18:02.173: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Pending", Reason="", readiness=false. Elapsed: 10.404119544s
... skipping 11 lines ...
Sep 22 11:18:26.970: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Running", Reason="", readiness=true. Elapsed: 35.200985885s
Sep 22 11:18:29.036: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Running", Reason="", readiness=true. Elapsed: 37.267309569s
Sep 22 11:18:31.103: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Running", Reason="", readiness=true. Elapsed: 39.334032329s
Sep 22 11:18:33.170: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Running", Reason="", readiness=true. Elapsed: 41.400988921s
Sep 22 11:18:35.235: INFO: Pod "pod-subpath-test-dynamicpv-7ttz": Phase="Succeeded", Reason="", readiness=false. Elapsed: 43.466445122s
STEP: Saw pod success
Sep 22 11:18:35.235: INFO: Pod "pod-subpath-test-dynamicpv-7ttz" satisfied condition "Succeeded or Failed"
Sep 22 11:18:35.300: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-7ttz container test-container-subpath-dynamicpv-7ttz: <nil>
STEP: delete the pod
Sep 22 11:18:35.440: INFO: Waiting for pod pod-subpath-test-dynamicpv-7ttz to disappear
Sep 22 11:18:35.504: INFO: Pod pod-subpath-test-dynamicpv-7ttz no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-7ttz
Sep 22 11:18:35.504: INFO: Deleting pod "pod-subpath-test-dynamicpv-7ttz" in namespace "provisioning-6958"
... skipping 542 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 295 lines ...
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/multivolume.go:320
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:20:05.212: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail if subpath file is outside the volume [Slow][LinuxOnly]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256
Sep 22 11:20:05.545: INFO: Creating resource for dynamic PV
Sep 22 11:20:05.545: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-5022-e2e-scthnk6
STEP: creating a claim
Sep 22 11:20:05.617: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-ckkf
STEP: Checking for subpath error in container status
Sep 22 11:20:21.960: INFO: Deleting pod "pod-subpath-test-dynamicpv-ckkf" in namespace "provisioning-5022"
Sep 22 11:20:22.032: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-ckkf" to be fully deleted
STEP: Deleting pod
Sep 22 11:20:34.165: INFO: Deleting pod "pod-subpath-test-dynamicpv-ckkf" in namespace "provisioning-5022"
STEP: Deleting pvc
Sep 22 11:20:34.362: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.com576mf"
... skipping 9 lines ...

• [SLOW TEST:34.581 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256
------------------------------
SSSS
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
... skipping 32 lines ...
Sep 22 11:20:26.773: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-3059-e2e-sctdvn4
STEP: creating a claim
Sep 22 11:20:26.840: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-kkhc
STEP: Creating a pod to test exec-volume-test
Sep 22 11:20:27.049: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-kkhc" in namespace "volume-3059" to be "Succeeded or Failed"
Sep 22 11:20:27.114: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Pending", Reason="", readiness=false. Elapsed: 64.964437ms
Sep 22 11:20:29.180: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.131366677s
Sep 22 11:20:31.247: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197689912s
Sep 22 11:20:33.313: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.264363918s
Sep 22 11:20:35.381: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.332555493s
Sep 22 11:20:37.448: INFO: Pod "exec-volume-test-dynamicpv-kkhc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.398691446s
STEP: Saw pod success
Sep 22 11:20:37.448: INFO: Pod "exec-volume-test-dynamicpv-kkhc" satisfied condition "Succeeded or Failed"
Sep 22 11:20:37.513: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod exec-volume-test-dynamicpv-kkhc container exec-container-dynamicpv-kkhc: <nil>
STEP: delete the pod
Sep 22 11:20:37.653: INFO: Waiting for pod exec-volume-test-dynamicpv-kkhc to disappear
Sep 22 11:20:37.718: INFO: Pod exec-volume-test-dynamicpv-kkhc no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-kkhc
Sep 22 11:20:37.718: INFO: Deleting pod "exec-volume-test-dynamicpv-kkhc" in namespace "volume-3059"
... skipping 17 lines ...
  [Testpattern: Dynamic PV (xfs)][Slow] volumes
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumes.go:196
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (block volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297

[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:20:39.823: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297
Sep 22 11:20:40.154: INFO: Creating resource for dynamic PV
Sep 22 11:20:40.154: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-53-e2e-sc29v7q
STEP: creating a claim
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep 22 11:20:44.623: INFO: Deleting pod "pod-0d43c103-17f8-4d96-91b9-06e6fb495724" in namespace "volumemode-53"
Sep 22 11:20:44.694: INFO: Wait up to 5m0s for pod "pod-0d43c103-17f8-4d96-91b9-06e6fb495724" to be fully deleted
STEP: Deleting pvc
Sep 22 11:20:54.961: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.coms6cwd"
Sep 22 11:20:55.029: INFO: Waiting up to 5m0s for PersistentVolume pvc-5b22237c-04b1-4204-8ba5-954f98b4d21e to get deleted
Sep 22 11:20:55.095: INFO: PersistentVolume pvc-5b22237c-04b1-4204-8ba5-954f98b4d21e found and phase=Released (66.614497ms)
... skipping 7 lines ...

• [SLOW TEST:20.553 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297
------------------------------
SS
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode 
  should not mount / map unused volumes in a pod [LinuxOnly]
... skipping 167 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 54 lines ...
Sep 22 11:18:30.254: INFO: Creating resource for dynamic PV
Sep 22 11:18:30.255: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-4199-e2e-sc42txr
STEP: creating a claim
Sep 22 11:18:30.319: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
Sep 22 11:18:30.515: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-7n6rg" in namespace "snapshotting-4199" to be "Succeeded or Failed"
Sep 22 11:18:30.579: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 63.253565ms
Sep 22 11:18:32.643: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127958564s
Sep 22 11:18:34.707: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.191965097s
Sep 22 11:18:36.773: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.257434207s
Sep 22 11:18:38.837: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.321294742s
Sep 22 11:18:40.901: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.385263111s
Sep 22 11:18:42.967: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 12.451372423s
Sep 22 11:18:45.036: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 14.520511856s
Sep 22 11:18:47.100: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 16.584783984s
Sep 22 11:18:49.165: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 18.649243597s
Sep 22 11:18:51.230: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Pending", Reason="", readiness=false. Elapsed: 20.714141697s
Sep 22 11:18:53.297: INFO: Pod "pvc-snapshottable-tester-7n6rg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.781369661s
STEP: Saw pod success
Sep 22 11:18:53.297: INFO: Pod "pvc-snapshottable-tester-7n6rg" satisfied condition "Succeeded or Failed"
Sep 22 11:18:53.425: INFO: Pod pvc-snapshottable-tester-7n6rg has the following logs: 
Sep 22 11:18:53.425: INFO: Deleting pod "pvc-snapshottable-tester-7n6rg" in namespace "snapshotting-4199"
Sep 22 11:18:53.496: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-7n6rg" to be fully deleted
Sep 22 11:18:53.560: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [ebs.csi.aws.comngf5q] to have phase Bound
Sep 22 11:18:53.623: INFO: PersistentVolumeClaim ebs.csi.aws.comngf5q found and phase=Bound (63.371234ms)
STEP: [init] checking the claim
... skipping 45 lines ...
[It] should check snapshot fields, check restore correctly works after modifying source data, check deletion
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:250
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep 22 11:20:00.471: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-w9xkg" in namespace "snapshotting-4199" to be "Succeeded or Failed"
Sep 22 11:20:00.538: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Pending", Reason="", readiness=false. Elapsed: 66.616927ms
Sep 22 11:20:02.608: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.136176566s
Sep 22 11:20:04.672: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.200182262s
Sep 22 11:20:06.737: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.265776235s
Sep 22 11:20:08.803: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.331837558s
Sep 22 11:20:10.868: INFO: Pod "pvc-snapshottable-data-tester-w9xkg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.396326102s
STEP: Saw pod success
Sep 22 11:20:10.868: INFO: Pod "pvc-snapshottable-data-tester-w9xkg" satisfied condition "Succeeded or Failed"
Sep 22 11:20:10.996: INFO: Pod pvc-snapshottable-data-tester-w9xkg has the following logs: 
Sep 22 11:20:10.996: INFO: Deleting pod "pvc-snapshottable-data-tester-w9xkg" in namespace "snapshotting-4199"
Sep 22 11:20:11.067: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-w9xkg" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the claim
Sep 22 11:20:33.387: INFO: Running '/usr/local/bin/kubectl --server=https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com --kubeconfig=/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig --namespace=snapshotting-4199 exec restored-pvc-tester-5lr4h --namespace=snapshotting-4199 -- cat /mnt/test/data'
... skipping 34 lines ...
Sep 22 11:20:59.227: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:00.292: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:01.361: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:02.426: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:03.490: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:04.554: INFO: volumesnapshotcontents snapcontent-65b2a9f2-6132-4281-8fb7-ddb9634cc20d has been found and is not deleted
Sep 22 11:21:05.556: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:228
Sep 22 11:21:05.621: INFO: Pod restored-pvc-tester-5lr4h has the following logs: unable to retrieve container logs for containerd://2422ad6d866049a885ac31b72ae5572da81ba63d549a8d568428242867ea743a
Sep 22 11:21:05.621: INFO: Deleting pod "restored-pvc-tester-5lr4h" in namespace "snapshotting-4199"
Sep 22 11:21:05.686: INFO: Wait up to 5m0s for pod "restored-pvc-tester-5lr4h" to be fully deleted
Sep 22 11:21:13.815: INFO: deleting claim "snapshotting-4199"/"pvc-sdltk"
... skipping 42 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 549 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.003 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:267

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 383 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.002 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 193 lines ...
Sep 22 11:21:21.203: INFO: Creating resource for dynamic PV
Sep 22 11:21:21.203: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-9732-e2e-sc5xr6w
STEP: creating a claim
Sep 22 11:21:21.274: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
Sep 22 11:21:21.470: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-9zgx5" in namespace "snapshotting-9732" to be "Succeeded or Failed"
Sep 22 11:21:21.534: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 63.680903ms
Sep 22 11:21:23.600: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129162051s
Sep 22 11:21:25.671: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.200384233s
Sep 22 11:21:27.741: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270931899s
Sep 22 11:21:29.809: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.338604908s
Sep 22 11:21:31.878: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.407420013s
Sep 22 11:21:33.943: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 12.472466508s
Sep 22 11:21:36.008: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 14.537499556s
Sep 22 11:21:38.074: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 16.603235469s
Sep 22 11:21:40.142: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 18.67126775s
Sep 22 11:21:42.210: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Pending", Reason="", readiness=false. Elapsed: 20.739714664s
Sep 22 11:21:44.275: INFO: Pod "pvc-snapshottable-tester-9zgx5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.804684252s
STEP: Saw pod success
Sep 22 11:21:44.275: INFO: Pod "pvc-snapshottable-tester-9zgx5" satisfied condition "Succeeded or Failed"
Sep 22 11:21:44.405: INFO: Pod pvc-snapshottable-tester-9zgx5 has the following logs: 
Sep 22 11:21:44.405: INFO: Deleting pod "pvc-snapshottable-tester-9zgx5" in namespace "snapshotting-9732"
Sep 22 11:21:44.473: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-9zgx5" to be fully deleted
Sep 22 11:21:44.537: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [ebs.csi.aws.comr876d] to have phase Bound
Sep 22 11:21:44.602: INFO: PersistentVolumeClaim ebs.csi.aws.comr876d found and phase=Bound (64.408882ms)
STEP: [init] checking the claim
... skipping 71 lines ...
[It] should check snapshot fields, check restore correctly works after modifying source data, check deletion
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/snapshottable.go:250
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep 22 11:23:04.738: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-5dkzm" in namespace "snapshotting-9732" to be "Succeeded or Failed"
Sep 22 11:23:04.810: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 71.779341ms
Sep 22 11:23:06.878: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.139612002s
Sep 22 11:23:08.950: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.211760585s
Sep 22 11:23:11.021: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.28316132s
Sep 22 11:23:13.085: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.347369156s
Sep 22 11:23:15.153: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.415234345s
Sep 22 11:23:17.217: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 12.47938353s
Sep 22 11:23:19.285: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 14.546582627s
Sep 22 11:23:21.348: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Pending", Reason="", readiness=false. Elapsed: 16.610262377s
Sep 22 11:23:23.411: INFO: Pod "pvc-snapshottable-data-tester-5dkzm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.673353356s
STEP: Saw pod success
Sep 22 11:23:23.412: INFO: Pod "pvc-snapshottable-data-tester-5dkzm" satisfied condition "Succeeded or Failed"
Sep 22 11:23:23.561: INFO: Pod pvc-snapshottable-data-tester-5dkzm has the following logs: 
Sep 22 11:23:23.562: INFO: Deleting pod "pvc-snapshottable-data-tester-5dkzm" in namespace "snapshotting-9732"
Sep 22 11:23:23.629: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-5dkzm" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the claim
Sep 22 11:23:45.971: INFO: Running '/usr/local/bin/kubectl --server=https://api-test-cluster-32322-k8-uptqek-1860249846.us-west-2.elb.amazonaws.com --kubeconfig=/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig --namespace=snapshotting-9732 exec restored-pvc-tester-7j7mc --namespace=snapshotting-9732 -- cat /mnt/test/data'
... skipping 203 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:278

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
S
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (delayed binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/topology.go:192

[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
Sep 22 11:25:05.237: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-32322.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/topology.go:192
Sep 22 11:25:05.640: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2a]
Sep 22 11:25:05.640: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2b]
Sep 22 11:25:05.640: INFO: Creating storage class object and pvc object for driver - sc: &StorageClass{ObjectMeta:{topology-6160-e2e-scdllvd      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:nil,MountOptions:[],AllowVolumeExpansion:nil,VolumeBindingMode:*WaitForFirstConsumer,AllowedTopologies:[]TopologySelectorTerm{{[{topology.ebs.csi.aws.com/zone [us-west-2b]}]},},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- topology-6160    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*topology-6160-e2e-scdllvd,VolumeMode:nil,DataSource:nil,DataSourceRef:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating sc
STEP: Creating pvc
... skipping 530 lines ...
Sep 22 11:25:45.155: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-289-e2e-scvzkg7
STEP: creating a claim
Sep 22 11:25:45.218: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-p6mm
STEP: Creating a pod to test exec-volume-test
Sep 22 11:25:45.410: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-p6mm" in namespace "volume-289" to be "Succeeded or Failed"
Sep 22 11:25:45.472: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 61.805241ms
Sep 22 11:25:47.534: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124328614s
Sep 22 11:25:49.597: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.187403327s
Sep 22 11:25:51.659: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.249503475s
Sep 22 11:25:53.723: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.312938246s
Sep 22 11:25:55.785: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.375153101s
Sep 22 11:25:57.848: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Pending", Reason="", readiness=false. Elapsed: 12.438078581s
Sep 22 11:25:59.911: INFO: Pod "exec-volume-test-dynamicpv-p6mm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.501418115s
STEP: Saw pod success
Sep 22 11:25:59.911: INFO: Pod "exec-volume-test-dynamicpv-p6mm" satisfied condition "Succeeded or Failed"
Sep 22 11:25:59.981: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod exec-volume-test-dynamicpv-p6mm container exec-container-dynamicpv-p6mm: <nil>
STEP: delete the pod
Sep 22 11:26:00.265: INFO: Waiting for pod exec-volume-test-dynamicpv-p6mm to disappear
Sep 22 11:26:00.328: INFO: Pod exec-volume-test-dynamicpv-p6mm no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-p6mm
Sep 22 11:26:00.328: INFO: Deleting pod "exec-volume-test-dynamicpv-p6mm" in namespace "volume-289"
... skipping 414 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 372 lines ...
Sep 22 11:27:16.649: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6419-e2e-scbrw88
STEP: creating a claim
Sep 22 11:27:16.714: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-fvc8
STEP: Creating a pod to test subpath
Sep 22 11:27:16.912: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-fvc8" in namespace "provisioning-6419" to be "Succeeded or Failed"
Sep 22 11:27:16.977: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 64.899133ms
Sep 22 11:27:19.043: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.130737758s
Sep 22 11:27:21.110: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197313263s
Sep 22 11:27:23.176: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.263389267s
Sep 22 11:27:25.241: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.328537922s
Sep 22 11:27:27.307: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.39436942s
Sep 22 11:27:29.372: INFO: Pod "pod-subpath-test-dynamicpv-fvc8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.459431753s
STEP: Saw pod success
Sep 22 11:27:29.372: INFO: Pod "pod-subpath-test-dynamicpv-fvc8" satisfied condition "Succeeded or Failed"
Sep 22 11:27:29.436: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-fvc8 container test-container-subpath-dynamicpv-fvc8: <nil>
STEP: delete the pod
Sep 22 11:27:29.587: INFO: Waiting for pod pod-subpath-test-dynamicpv-fvc8 to disappear
Sep 22 11:27:29.651: INFO: Pod pod-subpath-test-dynamicpv-fvc8 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-fvc8
Sep 22 11:27:29.651: INFO: Deleting pod "pod-subpath-test-dynamicpv-fvc8" in namespace "provisioning-6419"
... skipping 70 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:256

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 68 lines ...
Sep 22 11:27:25.303: INFO: Creating resource for dynamic PV
Sep 22 11:27:25.303: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-4562-e2e-scv5f4m
STEP: creating a claim
Sep 22 11:27:25.365: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod to format volume volume-prep-provisioning-4562
Sep 22 11:27:25.556: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-4562" in namespace "provisioning-4562" to be "Succeeded or Failed"
Sep 22 11:27:25.618: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 62.0265ms
Sep 22 11:27:27.681: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124973516s
Sep 22 11:27:29.744: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 4.187602928s
Sep 22 11:27:31.807: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 6.250518382s
Sep 22 11:27:33.870: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 8.313597003s
Sep 22 11:27:35.932: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 10.376012341s
Sep 22 11:27:37.995: INFO: Pod "volume-prep-provisioning-4562": Phase="Pending", Reason="", readiness=false. Elapsed: 12.438684503s
Sep 22 11:27:40.060: INFO: Pod "volume-prep-provisioning-4562": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.503964312s
STEP: Saw pod success
Sep 22 11:27:40.060: INFO: Pod "volume-prep-provisioning-4562" satisfied condition "Succeeded or Failed"
Sep 22 11:27:40.060: INFO: Deleting pod "volume-prep-provisioning-4562" in namespace "provisioning-4562"
Sep 22 11:27:40.128: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-4562" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-ktjj
STEP: Checking for subpath error in container status
Sep 22 11:27:46.385: INFO: Deleting pod "pod-subpath-test-dynamicpv-ktjj" in namespace "provisioning-4562"
Sep 22 11:27:46.453: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-ktjj" to be fully deleted
STEP: Deleting pod
Sep 22 11:27:46.515: INFO: Deleting pod "pod-subpath-test-dynamicpv-ktjj" in namespace "provisioning-4562"
STEP: Deleting pvc
Sep 22 11:27:46.701: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.coml2m4c"
... skipping 37 lines ...
Sep 22 11:27:46.292: INFO: Using claimSize:1Gi, test suite supported size:{ 1Gi}, driver(ebs.csi.aws.com) supported size:{ 1Gi} 
STEP: creating a StorageClass volume-expand-8744-e2e-scbkclj
STEP: creating a claim
Sep 22 11:27:46.361: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Expanding non-expandable pvc
Sep 22 11:27:46.496: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep 22 11:27:46.628: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:48.759: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:50.847: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:52.758: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:54.758: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:56.759: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:27:58.761: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:00.760: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:02.768: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:04.760: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:06.760: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:08.761: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:10.760: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:12.759: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:14.763: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:16.759: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-8744-e2e-scbkclj",
  	... // 2 identical fields
  }

Sep 22 11:28:16.891: INFO: Error updating pvc ebs.csi.aws.com6tbn9: PersistentVolumeClaim "ebs.csi.aws.com6tbn9" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 241 lines ...
Sep 22 11:28:18.083: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2801-e2e-scdmlj2
STEP: creating a claim
Sep 22 11:28:18.148: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-8sdg
STEP: Creating a pod to test subpath
Sep 22 11:28:18.346: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-8sdg" in namespace "provisioning-2801" to be "Succeeded or Failed"
Sep 22 11:28:18.410: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 64.213755ms
Sep 22 11:28:20.476: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129595311s
Sep 22 11:28:22.543: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.196948961s
Sep 22 11:28:24.611: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.264963522s
Sep 22 11:28:26.677: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.330833502s
Sep 22 11:28:28.741: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.395233215s
Sep 22 11:28:30.806: INFO: Pod "pod-subpath-test-dynamicpv-8sdg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.459769259s
STEP: Saw pod success
Sep 22 11:28:30.806: INFO: Pod "pod-subpath-test-dynamicpv-8sdg" satisfied condition "Succeeded or Failed"
Sep 22 11:28:30.870: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-8sdg container test-container-volume-dynamicpv-8sdg: <nil>
STEP: delete the pod
Sep 22 11:28:31.007: INFO: Waiting for pod pod-subpath-test-dynamicpv-8sdg to disappear
Sep 22 11:28:31.070: INFO: Pod pod-subpath-test-dynamicpv-8sdg no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-8sdg
Sep 22 11:28:31.070: INFO: Deleting pod "pod-subpath-test-dynamicpv-8sdg" in namespace "provisioning-2801"
... skipping 41 lines ...
Sep 22 11:28:02.600: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-9298-e2e-sc9vmg9
STEP: creating a claim
Sep 22 11:28:02.663: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-qbtd
STEP: Creating a pod to test subpath
Sep 22 11:28:02.867: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-qbtd" in namespace "provisioning-9298" to be "Succeeded or Failed"
Sep 22 11:28:02.930: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 62.311467ms
Sep 22 11:28:04.992: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.124924117s
Sep 22 11:28:07.058: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.190249056s
Sep 22 11:28:09.121: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.254020392s
Sep 22 11:28:11.185: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.318073498s
Sep 22 11:28:13.248: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.380857554s
Sep 22 11:28:15.311: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 12.444093297s
Sep 22 11:28:17.375: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 14.507785558s
Sep 22 11:28:19.438: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 16.57089671s
Sep 22 11:28:21.502: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 18.63433771s
Sep 22 11:28:23.565: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Pending", Reason="", readiness=false. Elapsed: 20.697660376s
Sep 22 11:28:25.628: INFO: Pod "pod-subpath-test-dynamicpv-qbtd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 22.760659863s
STEP: Saw pod success
Sep 22 11:28:25.628: INFO: Pod "pod-subpath-test-dynamicpv-qbtd" satisfied condition "Succeeded or Failed"
Sep 22 11:28:25.689: INFO: Trying to get logs from node ip-172-20-99-50.us-west-2.compute.internal pod pod-subpath-test-dynamicpv-qbtd container test-container-subpath-dynamicpv-qbtd: <nil>
STEP: delete the pod
Sep 22 11:28:25.831: INFO: Waiting for pod pod-subpath-test-dynamicpv-qbtd to disappear
Sep 22 11:28:25.892: INFO: Pod pod-subpath-test-dynamicpv-qbtd no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-qbtd
Sep 22 11:28:25.892: INFO: Deleting pod "pod-subpath-test-dynamicpv-qbtd" in namespace "provisioning-9298"
... skipping 179 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 173 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/subpath.go:240

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 102 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/volumemode.go:297

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:262
------------------------------
... skipping 410 lines ...
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents [It]
    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208

    Unexpected error:
        <*errors.errorString | 0xc0003a7410>: {
            s: "Timeout occurred",
        }
        Timeout occurred
    occurred

    /home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/fsgroupchangepolicy.go:263
------------------------------


Summarizing 1 Failure:

[Fail] External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [It] (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents 
/home/prow/go/pkg/mod/k8s.io/kubernetes@v1.22.11/test/e2e/storage/testsuites/fsgroupchangepolicy.go:263

Ran 69 of 539 Specs in 1392.887 seconds
FAIL! -- 68 Passed | 1 Failed | 0 Pending | 470 Skipped


Ginkgo ran 1 suite in 24m35.432732403s
Test Suite Failed
+ TEST_PASSED=1
+ set -e
+ set +x
###
## TEST_PASSED: 1
#
... skipping 546 lines ...
  Device: "/dev/xvdba",
  InstanceId: "i-05adb10bfc527900d",
  State: "attaching",
  VolumeId: "vol-05152ffa99f2f4d19"
}
I0922 11:14:00.261537       1 cloud.go:655] Waiting for volume "vol-05152ffa99f2f4d19" state: actual=attaching, desired=attached
E0922 11:14:00.301405       1 manager.go:44] Error releasing device: release on device "/dev/xvdba" assigned to different volume: "vol-024802c1f135ac08a" vs "vol-05152ffa99f2f4d19"
I0922 11:14:00.301425       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-024802c1f135ac08a detached from node i-05adb10bfc527900d
I0922 11:14:01.329524       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdba -> volume vol-05152ffa99f2f4d19
I0922 11:14:01.329543       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-05152ffa99f2f4d19 attached to node i-05adb10bfc527900d through device /dev/xvdba
I0922 11:14:01.337340       1 controller.go:316] ControllerPublishVolume: called with args {VolumeId:vol-05152ffa99f2f4d19 NodeId:i-05adb10bfc527900d VolumeCapability:mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1663845052526-8081-ebs.csi.aws.com] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0922 11:14:01.551390       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-05152ffa99f2f4d19 attached to node i-05adb10bfc527900d through device /dev/xvdba
I0922 11:14:12.411327       1 controller.go:103] CreateVolume: called with args {Name:pvc-fbd5272e-155b-4a02-a4e3-295ca4391ea9 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[csi.storage.k8s.io/pv/name:pvc-fbd5272e-155b-4a02-a4e3-295ca4391ea9 csi.storage.k8s.io/pvc/name:pvc-qkpg5 csi.storage.k8s.io/pvc/namespace:snapshotting-5797] Secrets:map[] VolumeContentSource:snapshot:<snapshot_id:"snap-0bed8e217272d7f60" >  AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2b" > > requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2a" > > requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2c" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2c" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2a" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
... skipping 680 lines ...
  VolumeId: "vol-04ebb75780f5fc016"
}
I0922 11:16:59.707932       1 cloud.go:655] Waiting for volume "vol-04ebb75780f5fc016" state: actual=attaching, desired=attached
I0922 11:17:00.046636       1 controller.go:538] CreateSnapshot: called with args source_volume_id:"vol-077ccb171615c99f5" name:"snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0" 
I0922 11:17:00.076083       1 controller.go:562] Snapshot snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0 of volume vol-077ccb171615c99f5 already exists; nothing to do
I0922 11:17:00.076101       1 inflight.go:74] Node Service: volume="snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0" operation finished
E0922 11:17:00.589581       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-0b555ed8cb171201a" vs "vol-04ebb75780f5fc016"
I0922 11:17:00.589600       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-0b555ed8cb171201a detached from node i-05adb10bfc527900d
I0922 11:17:00.647107       1 controller.go:538] CreateSnapshot: called with args source_volume_id:"vol-077ccb171615c99f5" name:"snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0" 
I0922 11:17:00.679303       1 controller.go:562] Snapshot snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0 of volume vol-077ccb171615c99f5 already exists; nothing to do
I0922 11:17:00.679322       1 inflight.go:74] Node Service: volume="snapshot-53d4c946-c6c3-48b4-aa0e-59912ab9c0a0" operation finished
I0922 11:17:00.777265       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbb -> volume vol-04ebb75780f5fc016
I0922 11:17:00.777285       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-04ebb75780f5fc016 attached to node i-05adb10bfc527900d through device /dev/xvdbb
... skipping 822 lines ...
I0922 11:19:57.657845       1 inflight.go:74] Node Service: volume="snapshot-65b2a9f2-6132-4281-8fb7-ddb9634cc20d" operation finished
I0922 11:19:58.234285       1 controller.go:538] CreateSnapshot: called with args source_volume_id:"vol-07f98934e70e28e86" name:"snapshot-65b2a9f2-6132-4281-8fb7-ddb9634cc20d" 
I0922 11:19:58.273410       1 controller.go:562] Snapshot snapshot-65b2a9f2-6132-4281-8fb7-ddb9634cc20d of volume vol-07f98934e70e28e86 already exists; nothing to do
I0922 11:19:58.273429       1 inflight.go:74] Node Service: volume="snapshot-65b2a9f2-6132-4281-8fb7-ddb9634cc20d" operation finished
I0922 11:20:00.257945       1 inflight.go:74] Node Service: volume="pvc-9f962d13-16f0-4e59-a164-70620ab082bc" operation finished
I0922 11:20:00.500952       1 controller.go:316] ControllerPublishVolume: called with args {VolumeId:vol-07f98934e70e28e86 NodeId:i-05adb10bfc527900d VolumeCapability:mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1663845052526-8081-ebs.csi.aws.com] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
E0922 11:20:00.761603       1 manager.go:44] Error releasing device: release on device "/dev/xvdba" assigned to different volume: "vol-0b30c519931d40e20" vs "vol-07f98934e70e28e86"
I0922 11:20:00.761631       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-0b30c519931d40e20 detached from node i-05adb10bfc527900d
I0922 11:20:00.905771       1 controller.go:316] ControllerPublishVolume: called with args {VolumeId:vol-070829abb33f98533 NodeId:i-05adb10bfc527900d VolumeCapability:mount:<fs_type:"xfs" > access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1663845052526-8081-ebs.csi.aws.com] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0922 11:20:01.117304       1 cloud.go:482] [Debug] AttachVolume volume="vol-07f98934e70e28e86" instance="i-05adb10bfc527900d" request returned {
  AttachTime: 2022-09-22 11:20:01.096 +0000 UTC,
  Device: "/dev/xvdba",
  InstanceId: "i-05adb10bfc527900d",
... skipping 33 lines ...
  Device: "/dev/xvdbb",
  InstanceId: "i-05adb10bfc527900d",
  State: "attaching",
  VolumeId: "vol-0fd3ccb52dac2ab23"
}
I0922 11:20:10.672141       1 cloud.go:655] Waiting for volume "vol-0fd3ccb52dac2ab23" state: actual=attaching, desired=attached
E0922 11:20:10.820162       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-080a5f3e10ec6b12f" vs "vol-0fd3ccb52dac2ab23"
I0922 11:20:10.820182       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-080a5f3e10ec6b12f detached from node i-05adb10bfc527900d
I0922 11:20:10.827433       1 cloud.go:655] Waiting for volume "vol-07241f779e8e7a5c0" state: actual=detaching, desired=detached
I0922 11:20:10.832578       1 controller.go:375] ControllerUnpublishVolume: called with args {VolumeId:vol-080a5f3e10ec6b12f NodeId:i-05adb10bfc527900d Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
W0922 11:20:10.882339       1 cloud.go:529] DetachDisk called on non-attached volume: vol-080a5f3e10ec6b12f
I0922 11:20:11.251275       1 controller.go:103] CreateVolume: called with args {Name:pvc-06538f47-6a95-4344-bfab-f2980e1b8fc5 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[csi.storage.k8s.io/pv/name:pvc-06538f47-6a95-4344-bfab-f2980e1b8fc5 csi.storage.k8s.io/pvc/name:pvc-sdltk csi.storage.k8s.io/pvc/namespace:snapshotting-4199] Secrets:map[] VolumeContentSource:snapshot:<snapshot_id:"snap-0687f42d1dcfe04ec" >  AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2c" > > requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2b" > > requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2a" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2c" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2a" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"us-west-2b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0922 11:20:11.739792       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbb -> volume vol-0fd3ccb52dac2ab23
... skipping 8 lines ...
  Device: "/dev/xvdbc",
  InstanceId: "i-05adb10bfc527900d",
  State: "attaching",
  VolumeId: "vol-0e202cef75ccd225b"
}
I0922 11:20:16.034923       1 cloud.go:655] Waiting for volume "vol-0e202cef75ccd225b" state: actual=attaching, desired=attached
E0922 11:20:16.723469       1 manager.go:44] Error releasing device: release on device "/dev/xvdbc" assigned to different volume: "vol-07241f779e8e7a5c0" vs "vol-0e202cef75ccd225b"
I0922 11:20:16.723486       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-07241f779e8e7a5c0 detached from node i-05adb10bfc527900d
I0922 11:20:17.094735       1 cloud.go:655] Waiting for volume "vol-0e202cef75ccd225b" state: actual=attaching, desired=attached
I0922 11:20:17.477523       1 cloud.go:655] Waiting for volume "vol-07f98934e70e28e86" state: actual=detaching, desired=detached
I0922 11:20:18.957858       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbc -> volume vol-0e202cef75ccd225b
I0922 11:20:18.957878       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-0e202cef75ccd225b attached to node i-05adb10bfc527900d through device /dev/xvdbc
I0922 11:20:18.977168       1 controller.go:283] DeleteVolume: called with args: {VolumeId:vol-07241f779e8e7a5c0 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
... skipping 695 lines ...
}
I0922 11:23:31.988498       1 cloud.go:655] Waiting for volume "vol-0e37ded1ede6ff0df" state: actual=attaching, desired=attached
I0922 11:23:33.084122       1 cloud.go:655] Waiting for volume "vol-0e37ded1ede6ff0df" state: actual=attaching, desired=attached
I0922 11:23:34.844700       1 cloud.go:655] Waiting for volume "vol-0e083e48f18b26093" state: actual=attaching, desired=attached
I0922 11:23:34.941709       1 cloud.go:655] Waiting for volume "vol-0e37ded1ede6ff0df" state: actual=attaching, desired=attached
I0922 11:23:36.887106       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-0bacd4d0e525f0557 detached from node i-05adb10bfc527900d
E0922 11:23:36.895206       1 manager.go:44] Error releasing device: release on device "/dev/xvdbc" assigned to different volume: "vol-099e01bc4e2dc31fa" vs "vol-0e37ded1ede6ff0df"
I0922 11:23:36.895226       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-099e01bc4e2dc31fa detached from node i-05adb10bfc527900d
I0922 11:23:36.963404       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-0bf517e442c6c3352 detached from node i-05adb10bfc527900d
I0922 11:23:36.976425       1 controller.go:375] ControllerUnpublishVolume: called with args {VolumeId:vol-0bf517e442c6c3352 NodeId:i-05adb10bfc527900d Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
W0922 11:23:37.016372       1 cloud.go:529] DetachDisk called on non-attached volume: vol-0bf517e442c6c3352
I0922 11:23:38.245576       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbc -> volume vol-0e37ded1ede6ff0df
I0922 11:23:38.245596       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-0e37ded1ede6ff0df attached to node i-05adb10bfc527900d through device /dev/xvdbc
... skipping 322 lines ...
  Device: "/dev/xvdbb",
  InstanceId: "i-05adb10bfc527900d",
  State: "attaching",
  VolumeId: "vol-0924e088508f85ef1"
}
I0922 11:25:20.793426       1 cloud.go:655] Waiting for volume "vol-0924e088508f85ef1" state: actual=attaching, desired=attached
E0922 11:25:21.055242       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-00759fea0f8aaf543" vs "vol-0924e088508f85ef1"
I0922 11:25:21.055259       1 controller.go:389] [Debug] ControllerUnpublishVolume: volume vol-00759fea0f8aaf543 detached from node i-05adb10bfc527900d
I0922 11:25:21.067523       1 controller.go:375] ControllerUnpublishVolume: called with args {VolumeId:vol-00759fea0f8aaf543 NodeId:i-05adb10bfc527900d Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
W0922 11:25:21.103869       1 cloud.go:529] DetachDisk called on non-attached volume: vol-00759fea0f8aaf543
I0922 11:25:21.124355       1 cloud.go:655] Waiting for volume "vol-075918fcb47a0eb12" state: actual=detaching, desired=detached
I0922 11:25:21.486760       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbd -> volume vol-0e8d266d488a4e804
I0922 11:25:21.486777       1 controller.go:344] [Debug] ControllerPublishVolume: volume vol-0e8d266d488a4e804 attached to node i-05adb10bfc527900d through device /dev/xvdbd
... skipping 5142 lines ...

Deleted cluster: "test-cluster-32322.k8s.local"
###
## OVERALL_TEST_PASSED: 1
#
###
## FAIL!
#
make: *** [Makefile:190: test-e2e-external] Error 1
+ EXIT_VALUE=2
+ set +o xtrace
Cleaning up after docker in docker.
================================================================================
Cleaning up after docker
Stopping Docker: dockerProgram process in pidfile '/var/run/docker-ssd.pid', 1 process(es), refused to die.
... skipping 3 lines ...