This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 1 failed / 176 succeeded
Started2020-01-17 12:51
Elapsed6h43m
Revision
Buildergke-prow-default-pool-cf4891d4-mzhc
links{u'resultstore': {u'url': u'https://source.cloud.google.com/results/invocations/260dd7d3-189b-4039-ae6e-d4f1b9a8ba98/targets/test'}}
podfc50a326-3927-11ea-8780-468616f72408
resultstorehttps://source.cloud.google.com/results/invocations/260dd7d3-189b-4039-ae6e-d4f1b9a8ba98/targets/test
infra-commitf3c464c7f
job-versionv1.15.9-beta.0.1+576595374055cc
master_os_imagecos-73-11647-163-0
node_os_imagecos-73-11647-163-0
podfc50a326-3927-11ea-8780-468616f72408
revisionv1.15.9-beta.0.1+576595374055cc

Test Failures


listResources After 1m20s

Failed to list resources (error during ./cluster/gce/list-resources.sh: exit status 2):
Project: k8s-e2e-gce-scalability
Region: 
Zone: 
Instance prefix: test-9b5ed62f1f
Network: test-9b5ed62f1f
Provider: gce


[ compute instance-templates ]



[ compute instance-groups ]



[ compute instances ]

				from junit_runner.xml

Filter through log files | View test history on testgrid


Show 176 Passed Tests

Show 4252 Skipped Tests

Error lines from build-log.txt

... skipping 15 lines ...
I0117 12:51:44.550] process 47 exited with code 0 after 0.0m
I0117 12:51:44.550] Will upload results to gs://kubernetes-jenkins/logs using pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com
I0117 12:51:44.550] Root: /workspace
I0117 12:51:44.550] cd to /workspace
I0117 12:51:44.550] Configure environment...
I0117 12:51:44.551] Call:  git show -s --format=format:%ct HEAD
W0117 12:51:44.557] fatal: not a git repository (or any of the parent directories): .git
I0117 12:51:44.557] process 60 exited with code 128 after 0.0m
W0117 12:51:44.557] Unable to print commit date for HEAD
I0117 12:51:44.558] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0117 12:51:45.255] Activated service account credentials for: [pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com]
I0117 12:51:45.604] process 61 exited with code 0 after 0.0m
I0117 12:51:45.604] Call:  gcloud config get-value account
... skipping 156 lines ...
W0117 12:52:53.919] Project: k8s-e2e-gce-scalability
W0117 12:52:53.920] Network Project: k8s-e2e-gce-scalability
W0117 12:52:53.920] Zone: us-west1-b
W0117 12:52:56.898] INSTANCE_GROUPS=
W0117 12:52:56.899] NODE_NAMES=
I0117 12:52:57.000] Bringing down cluster
W0117 12:52:59.950] ERROR: (gcloud.compute.instances.list) Some requests did not succeed:
W0117 12:52:59.951]  - Invalid value for field 'zone': 'asia-northeast3-a'. Unknown zone.
W0117 12:52:59.951]  - Invalid value for field 'zone': 'asia-northeast3-b'. Unknown zone.
W0117 12:52:59.951]  - Invalid value for field 'zone': 'asia-northeast3-c'. Unknown zone.
W0117 12:52:59.952] 
W0117 12:53:01.854] ERROR: (gcloud.compute.instances.list) Some requests did not succeed:
W0117 12:53:01.854]  - Invalid value for field 'zone': 'asia-northeast3-a'. Unknown zone.
W0117 12:53:01.854]  - Invalid value for field 'zone': 'asia-northeast3-b'. Unknown zone.
W0117 12:53:01.855]  - Invalid value for field 'zone': 'asia-northeast3-c'. Unknown zone.
W0117 12:53:01.855] 
W0117 12:53:05.648] ERROR: (gcloud.compute.instances.list) Some requests did not succeed:
W0117 12:53:05.649]  - Invalid value for field 'zone': 'asia-northeast3-a'. Unknown zone.
W0117 12:53:05.649]  - Invalid value for field 'zone': 'asia-northeast3-b'. Unknown zone.
W0117 12:53:05.649]  - Invalid value for field 'zone': 'asia-northeast3-c'. Unknown zone.
W0117 12:53:05.649] 
W0117 12:53:11.322] ERROR: (gcloud.compute.instances.list) Some requests did not succeed:
W0117 12:53:11.322]  - Invalid value for field 'zone': 'asia-northeast3-a'. Unknown zone.
W0117 12:53:11.323]  - Invalid value for field 'zone': 'asia-northeast3-b'. Unknown zone.
W0117 12:53:11.323]  - Invalid value for field 'zone': 'asia-northeast3-c'. Unknown zone.
W0117 12:53:11.323] 
I0117 12:53:19.877] Deleting firewall rules remaining in network test-9b5ed62f1f: 
I0117 12:53:22.302] Property "clusters.k8s-e2e-gce-scalability_test-9b5ed62f1f" unset.
... skipping 4 lines ...
I0117 12:53:22.868] Done
W0117 12:53:22.969] 2020/01/17 12:53:22 process.go:155: Step './hack/e2e-internal/e2e-down.sh' finished in 33.720774369s
W0117 12:53:22.969] 2020/01/17 12:53:22 e2e.go:456: Listing resources...
W0117 12:53:22.970] 2020/01/17 12:53:22 process.go:153: Running: ./cluster/gce/list-resources.sh
W0117 12:53:23.755] Listed 0 items.
W0117 12:53:24.848] Listed 0 items.
W0117 12:53:26.309] ERROR: (gcloud.compute.instances.list) Some requests did not succeed:
W0117 12:53:26.309]  - Invalid value for field 'zone': 'asia-northeast3-a'. Unknown zone.
W0117 12:53:26.309]  - Invalid value for field 'zone': 'asia-northeast3-b'. Unknown zone.
W0117 12:53:26.309]  - Invalid value for field 'zone': 'asia-northeast3-c'. Unknown zone.
W0117 12:53:26.310] 
W0117 12:53:26.406] Attempt 1 failed to list instances. Retrying.
W0117 12:53:38.056] Listed 0 items.
W0117 12:53:39.152] Listed 0 items.
W0117 12:53:40.227] Listed 0 items.
W0117 12:53:42.365] 
W0117 12:53:42.365] To show all fields of the firewall, please show in JSON format: --format=json
W0117 12:53:42.365] To show all fields in table format, please see the examples in --help.
... skipping 133 lines ...
W0117 12:56:04.991] Trying to find master named 'test-9b5ed62f1f-master'
W0117 12:56:04.991] Looking for address 'test-9b5ed62f1f-master-ip'
W0117 12:56:06.037] Using master: test-9b5ed62f1f-master (external IP: 35.230.109.225)
I0117 12:56:06.138] Waiting up to 300 seconds for cluster initialization.
I0117 12:56:06.138] 
I0117 12:56:06.138]   This will continually check to see if the API for kubernetes is reachable.
I0117 12:56:06.138]   This may time out if there was some uncaught error during start up.
I0117 12:56:06.139] 
I0117 12:57:19.517] ................Kubernetes cluster created.
I0117 12:57:19.738] Cluster "k8s-e2e-gce-scalability_test-9b5ed62f1f" set.
I0117 12:57:19.937] User "k8s-e2e-gce-scalability_test-9b5ed62f1f" set.
I0117 12:57:20.145] Context "k8s-e2e-gce-scalability_test-9b5ed62f1f" created.
I0117 12:57:20.345] Switched to context "k8s-e2e-gce-scalability_test-9b5ed62f1f".
... skipping 23 lines ...
I0117 12:57:49.217] NAME                                STATUS                     ROLES    AGE   VERSION
I0117 12:57:49.218] test-9b5ed62f1f-master              Ready,SchedulingDisabled   <none>   8s    v1.15.9-beta.0.1+576595374055cc
I0117 12:57:49.220] test-9b5ed62f1f-minion-group-3x0c   Ready                      <none>   4s    v1.15.9-beta.0.1+576595374055cc
I0117 12:57:49.220] test-9b5ed62f1f-minion-group-93hj   Ready                      <none>   6s    v1.15.9-beta.0.1+576595374055cc
I0117 12:57:49.220] test-9b5ed62f1f-minion-group-d1hk   Ready                      <none>   6s    v1.15.9-beta.0.1+576595374055cc
I0117 12:57:49.921] Validate output:
I0117 12:57:50.341] NAME                 STATUS    MESSAGE             ERROR
I0117 12:57:50.341] etcd-1               Healthy   {"health":"true"}   
I0117 12:57:50.341] scheduler            Healthy   ok                  
I0117 12:57:50.341] controller-manager   Healthy   ok                  
I0117 12:57:50.342] etcd-0               Healthy   {"health":"true"}   
I0117 12:57:50.351] Cluster validation succeeded
W0117 12:57:50.452] Done, listing cluster services:
... skipping 107 lines ...
I0117 12:58:21.914] 
I0117 12:58:27.044] Jan 17 12:58:27.044: INFO: cluster-master-image: cos-73-11647-163-0
I0117 12:58:27.045] Jan 17 12:58:27.044: INFO: cluster-node-image: cos-73-11647-163-0
I0117 12:58:27.045] Jan 17 12:58:27.044: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 12:58:27.048] Jan 17 12:58:27.048: INFO: Waiting up to 30m0s for all (but 0) nodes to be schedulable
I0117 12:58:27.228] Jan 17 12:58:27.227: INFO: Waiting up to 10m0s for all pods (need at least 8) in namespace 'kube-system' to be running and ready
I0117 12:58:27.394] Jan 17 12:58:27.394: INFO: The status of Pod etcd-server-test-9b5ed62f1f-master is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 12:58:27.395] Jan 17 12:58:27.394: INFO: 25 / 26 pods in namespace 'kube-system' are running and ready (0 seconds elapsed)
I0117 12:58:27.395] Jan 17 12:58:27.394: INFO: expected 9 pod replicas in namespace 'kube-system', 9 are Running and Ready.
I0117 12:58:27.395] Jan 17 12:58:27.394: INFO: POD                                 NODE                    PHASE    GRACE  CONDITIONS
I0117 12:58:27.396] Jan 17 12:58:27.394: INFO: etcd-server-test-9b5ed62f1f-master  test-9b5ed62f1f-master  Pending         []
I0117 12:58:27.396] Jan 17 12:58:27.394: INFO: 
I0117 12:58:29.509] Jan 17 12:58:29.508: INFO: The status of Pod etcd-server-test-9b5ed62f1f-master is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 12:58:29.509] Jan 17 12:58:29.508: INFO: 25 / 26 pods in namespace 'kube-system' are running and ready (2 seconds elapsed)
I0117 12:58:29.511] Jan 17 12:58:29.508: INFO: expected 9 pod replicas in namespace 'kube-system', 9 are Running and Ready.
I0117 12:58:29.511] Jan 17 12:58:29.508: INFO: POD                                 NODE                    PHASE    GRACE  CONDITIONS
I0117 12:58:29.511] Jan 17 12:58:29.508: INFO: etcd-server-test-9b5ed62f1f-master  test-9b5ed62f1f-master  Pending         []
I0117 12:58:29.512] Jan 17 12:58:29.508: INFO: 
I0117 12:58:31.511] Jan 17 12:58:31.511: INFO: The status of Pod fluentd-gcp-v3.2.0-tbz82 is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 12:58:31.512] Jan 17 12:58:31.511: INFO: 25 / 26 pods in namespace 'kube-system' are running and ready (4 seconds elapsed)
I0117 12:58:31.512] Jan 17 12:58:31.511: INFO: expected 9 pod replicas in namespace 'kube-system', 9 are Running and Ready.
I0117 12:58:31.512] Jan 17 12:58:31.511: INFO: POD                       NODE                               PHASE    GRACE  CONDITIONS
I0117 12:58:31.513] Jan 17 12:58:31.511: INFO: fluentd-gcp-v3.2.0-tbz82  test-9b5ed62f1f-minion-group-93hj  Running  60s    [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:30 +0000 UTC ContainersNotReady containers with unready status: [fluentd-gcp prometheus-to-sd-exporter]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:30 +0000 UTC ContainersNotReady containers with unready status: [fluentd-gcp prometheus-to-sd-exporter]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  }]
I0117 12:58:31.513] Jan 17 12:58:31.511: INFO: 
I0117 12:58:33.519] Jan 17 12:58:33.519: INFO: The status of Pod fluentd-gcp-v3.2.0-bxtzn is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 12:58:33.519] Jan 17 12:58:33.519: INFO: 25 / 26 pods in namespace 'kube-system' are running and ready (6 seconds elapsed)
I0117 12:58:33.520] Jan 17 12:58:33.519: INFO: expected 9 pod replicas in namespace 'kube-system', 9 are Running and Ready.
I0117 12:58:33.520] Jan 17 12:58:33.519: INFO: POD                       NODE                               PHASE    GRACE  CONDITIONS
I0117 12:58:33.520] Jan 17 12:58:33.519: INFO: fluentd-gcp-v3.2.0-bxtzn  test-9b5ed62f1f-minion-group-93hj  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC ContainersNotReady containers with unready status: [fluentd-gcp prometheus-to-sd-exporter]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC ContainersNotReady containers with unready status: [fluentd-gcp prometheus-to-sd-exporter]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  }]
I0117 12:58:33.520] Jan 17 12:58:33.519: INFO: 
I0117 12:58:35.510] Jan 17 12:58:35.510: INFO: 26 / 26 pods in namespace 'kube-system' are running and ready (8 seconds elapsed)
... skipping 535 lines ...
I0117 13:00:48.438] Jan 17 13:00:48.438: INFO: namespace sched-pred-5846 deletion completed in 7.502362852s
I0117 13:00:48.438] [AfterEach] [sig-scheduling] SchedulerPredicates [Serial]
I0117 13:00:48.439]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/scheduling/predicates.go:72
I0117 13:00:48.439] •SSSSSSSSSSSSSSSS
I0117 13:00:48.439] ------------------------------
I0117 13:00:48.440] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath 
I0117 13:00:48.440]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 13:00:48.440]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:00:48.440] [BeforeEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:00:48.441]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:00:48.441] Jan 17 13:00:48.438: INFO: Driver local doesn't support DynamicPV -- skipping
I0117 13:00:48.441] [AfterEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:00:48.441]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:00:48.442] [sig-storage] In-tree Volumes
I0117 13:00:48.442] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:00:48.442]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:00:48.442]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:00:48.443]     [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:00:48.443]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:00:48.443]       should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 13:00:48.443]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:00:48.443] 
I0117 13:00:48.444]       Driver local doesn't support DynamicPV -- skipping
I0117 13:00:48.444] 
I0117 13:00:48.444]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:00:48.444] ------------------------------
... skipping 73 lines ...
I0117 13:00:48.458] 
I0117 13:00:48.458]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:147
I0117 13:00:48.458] ------------------------------
I0117 13:00:48.459] SSSSSSSSSSSSS
I0117 13:00:48.459] ------------------------------
I0117 13:00:48.459] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Dynamic PV (block volmode)] volumeMode 
I0117 13:00:48.459]   should fail in binding dynamic provisioned PV to PVC
I0117 13:00:48.459]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:239
I0117 13:00:48.460] [BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
I0117 13:00:48.460]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:00:48.460] Jan 17 13:00:48.444: INFO: Driver local doesn't support DynamicPV -- skipping
I0117 13:00:48.460] [AfterEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
I0117 13:00:48.460]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:00:48.461] [sig-storage] In-tree Volumes
I0117 13:00:48.461] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:00:48.461]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:00:48.462]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:00:48.462]     [Testpattern: Dynamic PV (block volmode)] volumeMode
I0117 13:00:48.462]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:00:48.462]       should fail in binding dynamic provisioned PV to PVC [BeforeEach]
I0117 13:00:48.463]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:239
I0117 13:00:48.463] 
I0117 13:00:48.463]       Driver local doesn't support DynamicPV -- skipping
I0117 13:00:48.463] 
I0117 13:00:48.463]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:00:48.463] ------------------------------
... skipping 352 lines ...
I0117 13:04:21.704] 
I0117 13:04:21.704]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:147
I0117 13:04:21.704] ------------------------------
I0117 13:04:21.704] SSSSSS
I0117 13:04:21.704] ------------------------------
I0117 13:04:21.705] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Dynamic PV (default fs)] subPath 
I0117 13:04:21.705]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 13:04:21.705]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:04:21.705] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 13:04:21.705]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:04:21.705] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 13:04:21.706]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 13:04:21.706] STEP: Creating a kubernetes client
I0117 13:04:21.706] Jan 17 13:04:21.698: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 13:04:21.706] STEP: Building a namespace api object, basename provisioning
I0117 13:04:21.855] STEP: Waiting for a default service account to be provisioned in namespace
I0117 13:04:21.891] [It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 13:04:21.892]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:04:21.892] STEP: deploying csi gce-pd driver
I0117 13:04:21.927] Jan 17 13:04:21.926: INFO: Found CI service account key at /etc/service-account/service-account.json
I0117 13:04:21.927] Jan 17 13:04:21.926: INFO: Running cp [/etc/service-account/service-account.json /tmp/2255cd18-5675-4e07-bd1d-d2d1d08a8d40/cloud-sa.json]
I0117 13:04:21.966] Jan 17 13:04:21.966: INFO: Shredding file /tmp/2255cd18-5675-4e07-bd1d-d2d1d08a8d40/cloud-sa.json
I0117 13:04:21.967] Jan 17 13:04:21.966: INFO: Running shred [--remove /tmp/2255cd18-5675-4e07-bd1d-d2d1d08a8d40/cloud-sa.json]
... skipping 24 lines ...
I0117 13:04:22.771] Jan 17 13:04:22.770: INFO: creating *v1.StatefulSet: provisioning-8309/csi-gce-pd-controller
I0117 13:04:22.840] Jan 17 13:04:22.840: INFO: Test running for native CSI Driver, not checking metrics
I0117 13:04:22.841] Jan 17 13:04:22.840: INFO: Creating resource for dynamic PV
I0117 13:04:22.841] STEP: creating a StorageClass provisioning-8309-pd.csi.storage.gke.io-sc5p4dr
I0117 13:04:22.922] STEP: creating a claim
I0117 13:04:23.038] STEP: Creating pod pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-jjlw
I0117 13:04:23.081] STEP: Checking for subpath error in container status
I0117 13:04:53.152] Jan 17 13:04:53.152: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-jjlw" in namespace "provisioning-8309"
I0117 13:04:53.196] Jan 17 13:04:53.195: INFO: Wait up to 5m0s for pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-jjlw" to be fully deleted
I0117 13:04:59.268] STEP: Deleting pod
I0117 13:04:59.268] Jan 17 13:04:59.267: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-jjlw" in namespace "provisioning-8309"
I0117 13:04:59.303] STEP: Deleting pvc
I0117 13:04:59.303] Jan 17 13:04:59.302: INFO: Deleting PersistentVolumeClaim "pvc-wdvkm"
... skipping 63 lines ...
I0117 13:05:31.635] 
I0117 13:05:31.635]       Filesystem volume case should be covered by block volume case -- skipping
I0117 13:05:31.635] 
I0117 13:05:31.635]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:190
I0117 13:05:31.635] ------------------------------
I0117 13:05:31.636] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath 
I0117 13:05:31.636]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:05:31.636]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:05:31.636] [BeforeEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:05:31.636]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:05:31.637] Jan 17 13:05:31.632: INFO: Driver local doesn't support DynamicPV -- skipping
I0117 13:05:31.637] [AfterEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:05:31.637]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:05:31.638] [sig-storage] In-tree Volumes
I0117 13:05:31.638] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:05:31.638]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:05:31.638]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:05:31.638]     [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:05:31.638]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:05:31.639]       should fail if subpath with backstepping is outside the volume [Slow] [BeforeEach]
I0117 13:05:31.639]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:05:31.639] 
I0117 13:05:31.639]       Driver local doesn't support DynamicPV -- skipping
I0117 13:05:31.639] 
I0117 13:05:31.639]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:05:31.640] ------------------------------
... skipping 72 lines ...
I0117 13:06:36.526] STEP: Trying to apply a random label on the found node.
I0117 13:06:36.604] STEP: verifying the node has the label failure-domain.beta.kubernetes.io/zone equivalence-e2e-test
I0117 13:06:36.639] STEP: Trying to schedule RC with Pod Affinity should success.
I0117 13:06:41.873] STEP: Remove node failure domain label
I0117 13:06:41.873] STEP: removing the label failure-domain.beta.kubernetes.io/zone off the node test-9b5ed62f1f-minion-group-d1hk
I0117 13:06:41.954] STEP: verifying the node doesn't have the label failure-domain.beta.kubernetes.io/zone
I0117 13:06:41.989] STEP: Trying to schedule another equivalent Pod should fail due to node label has been removed.
I0117 13:06:42.025] STEP: Considering event: 
I0117 13:06:42.026] Type = [Normal], Name = [with-label-097287e7-963f-4271-818e-d4681988d047.15eaae6aa459384c], Reason = [Scheduled], Message = [Successfully assigned equivalence-cache-2700/with-label-097287e7-963f-4271-818e-d4681988d047 to test-9b5ed62f1f-minion-group-d1hk]
I0117 13:06:42.026] STEP: Considering event: 
I0117 13:06:42.026] Type = [Normal], Name = [with-label-097287e7-963f-4271-818e-d4681988d047.15eaae6b0ef5bf73], Reason = [Pulled], Message = [Container image "k8s.gcr.io/pause:3.1" already present on machine]
I0117 13:06:42.026] STEP: Considering event: 
I0117 13:06:42.027] Type = [Normal], Name = [with-label-097287e7-963f-4271-818e-d4681988d047.15eaae6b13b49e9f], Reason = [Created], Message = [Created container with-label-097287e7-963f-4271-818e-d4681988d047]
... skipping 33 lines ...
I0117 13:07:03.862] STEP: Destroying namespace "equivalence-cache-2700" for this suite.
I0117 13:07:11.971] Jan 17 13:07:11.970: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
I0117 13:07:13.403] Jan 17 13:07:13.399: INFO: namespace equivalence-cache-2700 deletion completed in 9.539770433s
I0117 13:07:13.404] •SSSS
I0117 13:07:13.404] ------------------------------
I0117 13:07:13.404] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 13:07:13.405]   should fail if subpath file is outside the volume [Slow][LinuxOnly]
I0117 13:07:13.405]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:232
I0117 13:07:13.405] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:07:13.406]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:07:13.406] Jan 17 13:07:13.400: INFO: Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 13:07:13.406] [AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:07:13.407]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:07:13.408] [sig-storage] CSI Volumes
I0117 13:07:13.408] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:07:13.409]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 13:07:13.409]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 13:07:13.410]     [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:07:13.410]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:07:13.411]       should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 13:07:13.411]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:232
I0117 13:07:13.411] 
I0117 13:07:13.412]       Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 13:07:13.412] 
I0117 13:07:13.412]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:07:13.413] ------------------------------
... skipping 569 lines ...
I0117 13:23:11.102] Jan 17 13:23:11.101: INFO: namespace sched-priority-1625 deletion completed in 21.731054334s
I0117 13:23:11.102] [AfterEach] [sig-scheduling] SchedulerPriorities [Serial]
I0117 13:23:11.102]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/scheduling/priorities.go:71
I0117 13:23:11.102] •SSSSSSSSSSS
I0117 13:23:11.103] ------------------------------
I0117 13:23:11.103] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath 
I0117 13:23:11.103]   should fail if subpath file is outside the volume [Slow][LinuxOnly]
I0117 13:23:11.103]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:232
I0117 13:23:11.104] [BeforeEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:23:11.104]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:23:11.104] Jan 17 13:23:11.102: INFO: Driver local doesn't support DynamicPV -- skipping
I0117 13:23:11.104] [AfterEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:23:11.104]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:23:11.105] [sig-storage] In-tree Volumes
I0117 13:23:11.105] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:23:11.105]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:23:11.105]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:23:11.105]     [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:23:11.106]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:23:11.106]       should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 13:23:11.106]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:232
I0117 13:23:11.106] 
I0117 13:23:11.106]       Driver local doesn't support DynamicPV -- skipping
I0117 13:23:11.106] 
I0117 13:23:11.106]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:23:11.106] ------------------------------
... skipping 21 lines ...
I0117 13:23:11.109] 
I0117 13:23:11.110]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:23:11.110] ------------------------------
I0117 13:23:11.110] SSSSSS
I0117 13:23:11.110] ------------------------------
I0117 13:23:11.110] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 13:23:11.110]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:23:11.111]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:23:11.111] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:23:11.111]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:23:11.111] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:23:11.111]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 13:23:11.111] STEP: Creating a kubernetes client
I0117 13:23:11.112] Jan 17 13:23:11.104: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 13:23:11.112] STEP: Building a namespace api object, basename provisioning
I0117 13:23:11.267] STEP: Waiting for a default service account to be provisioned in namespace
I0117 13:23:11.309] [It] should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:23:11.310]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:23:13.491] Jan 17 13:23:13.491: INFO: Running '/workspace/kubernetes/platforms/linux/amd64/kubectl --server=https://35.230.109.225 --kubeconfig=/workspace/.kube/config exec --namespace=provisioning-3197 hostexec-test-9b5ed62f1f-minion-group-3x0c -- nsenter --mount=/rootfs/proc/1/ns/mnt -- sh -c ls -1 /mnt/disks/by-uuid/google-local-ssds-scsi-fs/ | wc -l'
I0117 13:23:14.560] Jan 17 13:23:14.560: INFO: stderr: "ls: cannot access '/mnt/disks/by-uuid/google-local-ssds-scsi-fs/': No such file or directory\n"
I0117 13:23:14.561] Jan 17 13:23:14.560: INFO: stdout: "0\n"
I0117 13:23:14.561] Jan 17 13:23:14.560: INFO: Requires at least 1 scsi fs localSSD 
I0117 13:23:14.561] [AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 7 lines ...
I0117 13:23:22.380] [sig-storage] In-tree Volumes
I0117 13:23:22.381] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:23:22.381]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:23:22.381]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:23:22.381]     [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 13:23:22.381]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:23:22.382]       should fail if subpath with backstepping is outside the volume [Slow] [It]
I0117 13:23:22.382]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:23:22.382] 
I0117 13:23:22.382]       Requires at least 1 scsi fs localSSD 
I0117 13:23:22.382] 
I0117 13:23:22.382]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/drivers/in_tree.go:1720
I0117 13:23:22.383] ------------------------------
... skipping 960 lines ...
I0117 13:35:55.944] 
I0117 13:35:55.944]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:35:55.944] ------------------------------
I0117 13:35:55.945] SSSSSSSSSSSSSSSSSS
I0117 13:35:55.945] ------------------------------
I0117 13:35:55.945] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Inline-volume (default fs)] subPath 
I0117 13:35:55.945]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 13:35:55.945]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:35:55.946] [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:35:55.946]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:35:55.946] Jan 17 13:35:55.941: INFO: Driver local doesn't support InlineVolume -- skipping
I0117 13:35:55.946] [AfterEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:35:55.946]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:35:55.946] [sig-storage] In-tree Volumes
I0117 13:35:55.947] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:35:55.947]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:35:55.947]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:35:55.947]     [Testpattern: Inline-volume (default fs)] subPath
I0117 13:35:55.947]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:35:55.947]       should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 13:35:55.948]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:35:55.948] 
I0117 13:35:55.948]       Driver local doesn't support InlineVolume -- skipping
I0117 13:35:55.948] 
I0117 13:35:55.948]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:35:55.948] ------------------------------
... skipping 366 lines ...
I0117 13:37:14.258] 
I0117 13:37:14.258]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/drivers/in_tree.go:1416
I0117 13:37:14.258] ------------------------------
I0117 13:37:14.259] SSS
I0117 13:37:14.259] ------------------------------
I0117 13:37:14.259] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Inline-volume (default fs)] subPath 
I0117 13:37:14.259]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:37:14.259]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:37:14.260] [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:37:14.260]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:37:14.260] Jan 17 13:37:14.252: INFO: Driver pd.csi.storage.gke.io doesn't support InlineVolume -- skipping
I0117 13:37:14.260] [AfterEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:37:14.261]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:37:14.261] [sig-storage] CSI Volumes
I0117 13:37:14.261] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:37:14.261]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 13:37:14.261]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 13:37:14.261]     [Testpattern: Inline-volume (default fs)] subPath
I0117 13:37:14.262]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:37:14.262]       should fail if subpath with backstepping is outside the volume [Slow] [BeforeEach]
I0117 13:37:14.262]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:37:14.262] 
I0117 13:37:14.262]       Driver pd.csi.storage.gke.io doesn't support InlineVolume -- skipping
I0117 13:37:14.262] 
I0117 13:37:14.262]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:37:14.262] ------------------------------
... skipping 68 lines ...
I0117 13:39:41.061] Jan 17 13:39:41.060: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0117 13:39:41.103] STEP: Destroying namespace "pv-9800" for this suite.
I0117 13:39:55.231] Jan 17 13:39:55.231: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
I0117 13:39:56.959] Jan 17 13:39:56.959: INFO: namespace pv-9800 deletion completed in 15.85610927s
I0117 13:39:56.959] [AfterEach] [sig-storage] [Serial] Volume metrics
I0117 13:39:56.960]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/volume_metrics.go:76
I0117 13:39:57.000] Jan 17 13:39:57.000: INFO: Failed to get pvc pv-9800/pvc-7vwtj: persistentvolumeclaims "pvc-7vwtj" not found
I0117 13:39:57.000] •
I0117 13:39:57.000] ------------------------------
I0117 13:39:57.001] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 13:39:57.001]   should support non-existent path
I0117 13:39:57.001]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:170
I0117 13:39:57.001] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 144 lines ...
I0117 13:41:51.869] STEP: Destroying namespace "provisioning-3934" for this suite.
I0117 13:42:14.000] Jan 17 13:42:14.000: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
I0117 13:42:15.674] Jan 17 13:42:15.673: INFO: namespace provisioning-3934 deletion completed in 23.804796005s
I0117 13:42:15.674] •SSSSSS
I0117 13:42:15.674] ------------------------------
I0117 13:42:15.674] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Dynamic PV (default fs)] subPath 
I0117 13:42:15.675]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:42:15.675]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:42:15.675] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 13:42:15.675]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:42:15.676] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 13:42:15.676]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 13:42:15.676] STEP: Creating a kubernetes client
I0117 13:42:15.676] Jan 17 13:42:15.674: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 13:42:15.676] STEP: Building a namespace api object, basename provisioning
I0117 13:42:15.852] STEP: Waiting for a default service account to be provisioned in namespace
I0117 13:42:15.893] [It] should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:42:15.894]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:42:15.894] STEP: deploying csi gce-pd driver
I0117 13:42:15.936] Jan 17 13:42:15.936: INFO: Found CI service account key at /etc/service-account/service-account.json
I0117 13:42:15.937] Jan 17 13:42:15.936: INFO: Running cp [/etc/service-account/service-account.json /tmp/2e1d2387-6fea-42e8-b10a-f55d0895d543/cloud-sa.json]
I0117 13:42:15.984] Jan 17 13:42:15.983: INFO: Shredding file /tmp/2e1d2387-6fea-42e8-b10a-f55d0895d543/cloud-sa.json
I0117 13:42:15.984] Jan 17 13:42:15.983: INFO: Running shred [--remove /tmp/2e1d2387-6fea-42e8-b10a-f55d0895d543/cloud-sa.json]
... skipping 24 lines ...
I0117 13:42:16.968] Jan 17 13:42:16.968: INFO: creating *v1.StatefulSet: provisioning-2802/csi-gce-pd-controller
I0117 13:42:17.068] Jan 17 13:42:17.068: INFO: Test running for native CSI Driver, not checking metrics
I0117 13:42:17.068] Jan 17 13:42:17.068: INFO: Creating resource for dynamic PV
I0117 13:42:17.069] STEP: creating a StorageClass provisioning-2802-pd.csi.storage.gke.io-scml88k
I0117 13:42:17.179] STEP: creating a claim
I0117 13:42:17.321] STEP: Creating pod pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-t4zk
I0117 13:42:17.372] STEP: Checking for subpath error in container status
I0117 13:42:45.456] Jan 17 13:42:45.455: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-t4zk" in namespace "provisioning-2802"
I0117 13:42:45.504] Jan 17 13:42:45.503: INFO: Wait up to 5m0s for pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-t4zk" to be fully deleted
I0117 13:42:49.588] STEP: Deleting pod
I0117 13:42:49.588] Jan 17 13:42:49.587: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-t4zk" in namespace "provisioning-2802"
I0117 13:42:49.630] STEP: Deleting pvc
I0117 13:42:49.630] Jan 17 13:42:49.629: INFO: Deleting PersistentVolumeClaim "pvc-8b9hx"
... skipping 627 lines ...
I0117 13:47:06.430] Jan 17 13:47:06.429: INFO: Running '/workspace/kubernetes/platforms/linux/amd64/kubectl --server=https://35.230.109.225 --kubeconfig=/workspace/.kube/config exec --namespace=services-7582 execpod-b2psx -- /bin/sh -x -c for i in $(seq 1 150); do wget -q -T 1 -O - http://10.0.253.89:80 2>&1 || true; echo; done'
I0117 13:47:07.393] Jan 17 13:47:07.387: INFO: stderr: "+ seq 1 150\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n+ wget -q -T 1 -O - http://10.0.253.89:80\n+ echo\n"
I0117 13:47:07.396] Jan 17 13:47:07.387: INFO: stdout: "service1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-zxmts\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-qbjzp\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-zxmts\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-8684w\nservice1-qbjzp\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-qbjzp\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-qbjzp\nservice1-qbjzp\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\nservice1-zxmts\nservice1-8684w\nservice1-qbjzp\nservice1-zxmts\nservice1-qbjzp\nservice1-zxmts\nservice1-8684w\nservice1-8684w\nservice1-zxmts\nservice1-qbjzp\nservice1-zxmts\nservice1-zxmts\n"
I0117 13:47:07.396] STEP: Deleting pod execpod-b2psx in namespace services-7582
I0117 13:47:07.443] STEP: Restarting apiserver
I0117 13:47:07.487] Jan 17 13:47:07.487: INFO: Restarting master via ssh, running: pidof kube-apiserver | xargs sudo kill
I0117 13:47:08.090] Jan 17 13:47:08.090: INFO: Failed to get apiserver's restart count: Get https://35.230.109.225/api/v1/namespaces/kube-system/pods?labelSelector=component%3Dkube-apiserver: dial tcp 35.230.109.225:443: connect: connection refused
I0117 13:47:16.787] Jan 17 13:47:16.784: INFO: Waiting for apiserver restart count to increase
I0117 13:47:21.941] Jan 17 13:47:21.941: INFO: Apiserver has restarted.
I0117 13:47:21.942] STEP: Waiting for apiserver to come up by polling /healthz
I0117 13:47:27.120] Jan 17 13:47:27.120: INFO: Creating new exec pod
I0117 13:47:29.255] STEP: verifying service has 3 reachable backends
I0117 13:47:29.256] Jan 17 13:47:29.255: INFO: Executing cmd "set -e; for i in $(seq 1 150); do wget -q --timeout=0.2 --tries=1 -O - http://10.0.253.89:80 2>&1 || true; echo; done" on host 34.83.150.17:22
... skipping 277 lines ...
I0117 13:53:50.157] STEP: Destroying namespace "provisioning-3053" for this suite.
I0117 13:53:56.285] Jan 17 13:53:56.285: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
I0117 13:53:57.913] Jan 17 13:53:57.913: INFO: namespace provisioning-3053 deletion completed in 7.755495349s
I0117 13:53:57.913] •
I0117 13:53:57.913] ------------------------------
I0117 13:53:57.913] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Inline-volume (default fs)] subPath 
I0117 13:53:57.914]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 13:53:57.914]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:53:57.914] [BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:53:57.914]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:53:57.914] Jan 17 13:53:57.913: INFO: Driver local doesn't support InlineVolume -- skipping
I0117 13:53:57.915] [AfterEach] [Testpattern: Inline-volume (default fs)] subPath
I0117 13:53:57.915]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:53:57.916] [sig-storage] In-tree Volumes
I0117 13:53:57.916] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:53:57.916]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 13:53:57.916]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 13:53:57.916]     [Testpattern: Inline-volume (default fs)] subPath
I0117 13:53:57.916]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:53:57.917]       should fail if subpath with backstepping is outside the volume [Slow] [BeforeEach]
I0117 13:53:57.917]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 13:53:57.917] 
I0117 13:53:57.917]       Driver local doesn't support InlineVolume -- skipping
I0117 13:53:57.917] 
I0117 13:53:57.917]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:53:57.917] ------------------------------
... skipping 307 lines ...
I0117 13:57:23.754] 
I0117 13:57:23.754]       Driver gluster doesn't support DynamicPV -- skipping
I0117 13:57:23.755] 
I0117 13:57:23.755]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 13:57:23.755] ------------------------------
I0117 13:57:23.755] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath 
I0117 13:57:23.755]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 13:57:23.756]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:57:23.756] [BeforeEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:57:23.756]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 13:57:23.756] Jan 17 13:57:23.751: INFO: Driver pd.csi.storage.gke.io doesn't support ntfs -- skipping
I0117 13:57:23.756] [AfterEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:57:23.757]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 13:57:23.757] [sig-storage] CSI Volumes
I0117 13:57:23.758] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 13:57:23.758]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 13:57:23.758]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 13:57:23.758]     [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 13:57:23.758]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 13:57:23.759]       should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 13:57:23.759]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 13:57:23.759] 
I0117 13:57:23.759]       Driver pd.csi.storage.gke.io doesn't support ntfs -- skipping
I0117 13:57:23.759] 
I0117 13:57:23.759]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:147
I0117 13:57:23.760] ------------------------------
... skipping 781 lines ...
I0117 14:04:49.261] 
I0117 14:04:49.261]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 14:04:49.261] ------------------------------
I0117 14:04:49.262] SSS
I0117 14:04:49.262] ------------------------------
I0117 14:04:49.262] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 14:04:49.262]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 14:04:49.262]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 14:04:49.262] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:04:49.263]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 14:04:49.263] Jan 17 14:04:49.255: INFO: Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 14:04:49.263] [AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:04:49.263]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 14:04:49.264] [sig-storage] CSI Volumes
I0117 14:04:49.264] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 14:04:49.264]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 14:04:49.264]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 14:04:49.265]     [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:04:49.265]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 14:04:49.265]       should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
I0117 14:04:49.265]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 14:04:49.265] 
I0117 14:04:49.266]       Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 14:04:49.266] 
I0117 14:04:49.266]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 14:04:49.266] ------------------------------
... skipping 125 lines ...
I0117 14:08:30.907] Jan 17 14:08:30.906: INFO: Waiting for ready nodes 3, current ready 3, not ready nodes 1
I0117 14:08:50.950] Jan 17 14:08:50.949: INFO: Condition Ready of node test-9b5ed62f1f-minion-group-93hj is false, but Node is tainted by NodeController with [{node.kubernetes.io/unreachable  NoSchedule 2020-01-17 14:07:31 +0000 UTC} {node.kubernetes.io/unreachable  NoExecute 2020-01-17 14:07:36 +0000 UTC}]. Failure
I0117 14:08:50.950] Jan 17 14:08:50.949: INFO: Waiting for ready nodes 3, current ready 3, not ready nodes 1
I0117 14:09:10.994] Jan 17 14:09:10.994: INFO: Cluster has reached the desired number of ready nodes 3
I0117 14:09:10.994] STEP: waiting for system pods to successfully restart
I0117 14:09:10.994] Jan 17 14:09:10.994: INFO: Waiting up to 5m0s for all pods (need at least 0) in namespace 'kube-system' to be running and ready
I0117 14:09:11.130] Jan 17 14:09:11.130: INFO: The status of Pod coredns-557dcdc9f5-wvs9x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.131] Jan 17 14:09:11.130: INFO: The status of Pod fluentd-gcp-v3.2.0-bxtzn is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.131] Jan 17 14:09:11.130: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-c4hmv is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.131] Jan 17 14:09:11.130: INFO: The status of Pod kube-proxy-test-9b5ed62f1f-minion-group-93hj is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.132] Jan 17 14:09:11.130: INFO: The status of Pod l7-default-backend-84c9fcfbb-vnqp9 is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.132] Jan 17 14:09:11.130: INFO: The status of Pod metadata-proxy-v0.1-7t66x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:11.132] Jan 17 14:09:11.130: INFO: 25 / 31 pods in namespace 'kube-system' are running and ready (0 seconds elapsed)
I0117 14:09:11.132] Jan 17 14:09:11.130: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:11.132] Jan 17 14:09:11.130: INFO: POD                                           NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:11.133] Jan 17 14:09:11.130: INFO: coredns-557dcdc9f5-wvs9x                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:47 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  }]
I0117 14:09:11.133] Jan 17 14:09:11.130: INFO: fluentd-gcp-v3.2.0-bxtzn                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:34 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  }]
I0117 14:09:11.134] Jan 17 14:09:11.130: INFO: heapster-v1.6.0-beta.1-6b89b777b5-c4hmv       test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:59 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:04 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:58 +0000 UTC  }]
I0117 14:09:11.134] Jan 17 14:09:11.130: INFO: kube-proxy-test-9b5ed62f1f-minion-group-93hj  test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  }]
I0117 14:09:11.135] Jan 17 14:09:11.130: INFO: l7-default-backend-84c9fcfbb-vnqp9            test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:21 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  }]
I0117 14:09:11.135] Jan 17 14:09:11.130: INFO: metadata-proxy-v0.1-7t66x                     test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:57 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  }]
I0117 14:09:11.135] Jan 17 14:09:11.130: INFO: 
I0117 14:09:13.262] Jan 17 14:09:13.262: INFO: The status of Pod coredns-557dcdc9f5-wvs9x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.263] Jan 17 14:09:13.262: INFO: The status of Pod fluentd-gcp-v3.2.0-bxtzn is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.264] Jan 17 14:09:13.262: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-c4hmv is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.264] Jan 17 14:09:13.262: INFO: The status of Pod kube-proxy-test-9b5ed62f1f-minion-group-93hj is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.264] Jan 17 14:09:13.262: INFO: The status of Pod l7-default-backend-84c9fcfbb-vnqp9 is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.265] Jan 17 14:09:13.262: INFO: The status of Pod metadata-proxy-v0.1-7t66x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:13.265] Jan 17 14:09:13.262: INFO: 25 / 31 pods in namespace 'kube-system' are running and ready (2 seconds elapsed)
I0117 14:09:13.265] Jan 17 14:09:13.262: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:13.266] Jan 17 14:09:13.262: INFO: POD                                           NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:13.266] Jan 17 14:09:13.262: INFO: coredns-557dcdc9f5-wvs9x                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:47 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  }]
I0117 14:09:13.267] Jan 17 14:09:13.262: INFO: fluentd-gcp-v3.2.0-bxtzn                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:34 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  }]
I0117 14:09:13.268] Jan 17 14:09:13.262: INFO: heapster-v1.6.0-beta.1-6b89b777b5-c4hmv       test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:59 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:04 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:58 +0000 UTC  }]
I0117 14:09:13.268] Jan 17 14:09:13.262: INFO: kube-proxy-test-9b5ed62f1f-minion-group-93hj  test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  }]
I0117 14:09:13.269] Jan 17 14:09:13.262: INFO: l7-default-backend-84c9fcfbb-vnqp9            test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:21 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  }]
I0117 14:09:13.270] Jan 17 14:09:13.262: INFO: metadata-proxy-v0.1-7t66x                     test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:57 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  }]
I0117 14:09:13.270] Jan 17 14:09:13.262: INFO: 
I0117 14:09:15.264] Jan 17 14:09:15.263: INFO: The status of Pod coredns-557dcdc9f5-wvs9x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.264] Jan 17 14:09:15.263: INFO: The status of Pod fluentd-gcp-v3.2.0-bxtzn is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.265] Jan 17 14:09:15.263: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-c4hmv is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.265] Jan 17 14:09:15.264: INFO: The status of Pod kube-proxy-test-9b5ed62f1f-minion-group-93hj is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.265] Jan 17 14:09:15.264: INFO: The status of Pod l7-default-backend-84c9fcfbb-vnqp9 is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.265] Jan 17 14:09:15.264: INFO: The status of Pod metadata-proxy-v0.1-7t66x is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:15.265] Jan 17 14:09:15.264: INFO: 25 / 31 pods in namespace 'kube-system' are running and ready (4 seconds elapsed)
I0117 14:09:15.266] Jan 17 14:09:15.264: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:15.266] Jan 17 14:09:15.264: INFO: POD                                           NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:15.267] Jan 17 14:09:15.264: INFO: coredns-557dcdc9f5-wvs9x                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:47 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:01:40 +0000 UTC  }]
I0117 14:09:15.267] Jan 17 14:09:15.264: INFO: fluentd-gcp-v3.2.0-bxtzn                      test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:34 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:31 +0000 UTC  }]
I0117 14:09:15.268] Jan 17 14:09:15.264: INFO: heapster-v1.6.0-beta.1-6b89b777b5-c4hmv       test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:59 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:04 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:58 +0000 UTC  }]
I0117 14:09:15.268] Jan 17 14:09:15.264: INFO: kube-proxy-test-9b5ed62f1f-minion-group-93hj  test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 13:01:50 +0000 UTC  }]
I0117 14:09:15.269] Jan 17 14:09:15.264: INFO: l7-default-backend-84c9fcfbb-vnqp9            test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:21 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:58:07 +0000 UTC  }]
I0117 14:09:15.269] Jan 17 14:09:15.264: INFO: metadata-proxy-v0.1-7t66x                     test-9b5ed62f1f-minion-group-93hj  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:07:31 +0000 UTC  } {ContainersReady True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:57 +0000 UTC  } {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 12:57:44 +0000 UTC  }]
I0117 14:09:15.269] Jan 17 14:09:15.264: INFO: 
I0117 14:09:17.263] Jan 17 14:09:17.263: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:17.263] Jan 17 14:09:17.263: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-b4zgq is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:17.264] Jan 17 14:09:17.263: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:17.264] Jan 17 14:09:17.263: INFO: 25 / 28 pods in namespace 'kube-system' are running and ready (6 seconds elapsed)
I0117 14:09:17.264] Jan 17 14:09:17.263: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:17.264] Jan 17 14:09:17.263: INFO: POD                                      NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:17.265] Jan 17 14:09:17.263: INFO: coredns-557dcdc9f5-qtrkl                 test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:17.266] Jan 17 14:09:17.263: INFO: heapster-v1.6.0-beta.1-6b89b777b5-b4zgq  test-9b5ed62f1f-minion-group-s301  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:17.266] Jan 17 14:09:17.263: INFO: l7-default-backend-84c9fcfbb-np9rs       test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:17.266] Jan 17 14:09:17.263: INFO: 
I0117 14:09:19.266] Jan 17 14:09:19.266: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:19.267] Jan 17 14:09:19.266: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-b4zgq is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:19.268] Jan 17 14:09:19.266: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:19.268] Jan 17 14:09:19.266: INFO: 25 / 28 pods in namespace 'kube-system' are running and ready (8 seconds elapsed)
I0117 14:09:19.268] Jan 17 14:09:19.266: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:19.268] Jan 17 14:09:19.266: INFO: POD                                      NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:19.269] Jan 17 14:09:19.266: INFO: coredns-557dcdc9f5-qtrkl                 test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:19.270] Jan 17 14:09:19.266: INFO: heapster-v1.6.0-beta.1-6b89b777b5-b4zgq  test-9b5ed62f1f-minion-group-s301  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:19.271] Jan 17 14:09:19.266: INFO: l7-default-backend-84c9fcfbb-np9rs       test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:19.271] Jan 17 14:09:19.266: INFO: 
I0117 14:09:21.262] Jan 17 14:09:21.261: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:21.262] Jan 17 14:09:21.261: INFO: The status of Pod heapster-v1.6.0-beta.1-6b89b777b5-b4zgq is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:21.262] Jan 17 14:09:21.261: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:21.263] Jan 17 14:09:21.261: INFO: 25 / 28 pods in namespace 'kube-system' are running and ready (10 seconds elapsed)
I0117 14:09:21.263] Jan 17 14:09:21.261: INFO: expected 9 pod replicas in namespace 'kube-system', 6 are Running and Ready.
I0117 14:09:21.263] Jan 17 14:09:21.261: INFO: POD                                      NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:21.264] Jan 17 14:09:21.261: INFO: coredns-557dcdc9f5-qtrkl                 test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:21.265] Jan 17 14:09:21.261: INFO: heapster-v1.6.0-beta.1-6b89b777b5-b4zgq  test-9b5ed62f1f-minion-group-s301  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [heapster heapster-nanny]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:21.266] Jan 17 14:09:21.261: INFO: l7-default-backend-84c9fcfbb-np9rs       test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:21.266] Jan 17 14:09:21.261: INFO: 
I0117 14:09:23.262] Jan 17 14:09:23.262: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:23.263] Jan 17 14:09:23.262: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:23.263] Jan 17 14:09:23.262: INFO: 26 / 28 pods in namespace 'kube-system' are running and ready (12 seconds elapsed)
I0117 14:09:23.263] Jan 17 14:09:23.262: INFO: expected 9 pod replicas in namespace 'kube-system', 7 are Running and Ready.
I0117 14:09:23.264] Jan 17 14:09:23.262: INFO: POD                                 NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:23.264] Jan 17 14:09:23.262: INFO: coredns-557dcdc9f5-qtrkl            test-9b5ed62f1f-minion-group-x4ph  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:23.265] Jan 17 14:09:23.262: INFO: l7-default-backend-84c9fcfbb-np9rs  test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:23.265] Jan 17 14:09:23.262: INFO: 
I0117 14:09:25.262] Jan 17 14:09:25.262: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:25.262] Jan 17 14:09:25.262: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:25.263] Jan 17 14:09:25.262: INFO: 26 / 28 pods in namespace 'kube-system' are running and ready (14 seconds elapsed)
I0117 14:09:25.263] Jan 17 14:09:25.262: INFO: expected 9 pod replicas in namespace 'kube-system', 7 are Running and Ready.
I0117 14:09:25.263] Jan 17 14:09:25.262: INFO: POD                                 NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:25.264] Jan 17 14:09:25.262: INFO: coredns-557dcdc9f5-qtrkl            test-9b5ed62f1f-minion-group-x4ph  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:25.265] Jan 17 14:09:25.262: INFO: l7-default-backend-84c9fcfbb-np9rs  test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:25.265] Jan 17 14:09:25.262: INFO: 
I0117 14:09:27.265] Jan 17 14:09:27.265: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:27.265] Jan 17 14:09:27.265: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:27.265] Jan 17 14:09:27.265: INFO: 26 / 28 pods in namespace 'kube-system' are running and ready (16 seconds elapsed)
I0117 14:09:27.266] Jan 17 14:09:27.265: INFO: expected 9 pod replicas in namespace 'kube-system', 7 are Running and Ready.
I0117 14:09:27.266] Jan 17 14:09:27.265: INFO: POD                                 NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:27.267] Jan 17 14:09:27.265: INFO: coredns-557dcdc9f5-qtrkl            test-9b5ed62f1f-minion-group-x4ph  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:27.268] Jan 17 14:09:27.265: INFO: l7-default-backend-84c9fcfbb-np9rs  test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:27.268] Jan 17 14:09:27.265: INFO: 
I0117 14:09:29.263] Jan 17 14:09:29.262: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:29.263] Jan 17 14:09:29.263: INFO: The status of Pod l7-default-backend-84c9fcfbb-np9rs is Pending (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:29.264] Jan 17 14:09:29.263: INFO: 26 / 28 pods in namespace 'kube-system' are running and ready (18 seconds elapsed)
I0117 14:09:29.264] Jan 17 14:09:29.263: INFO: expected 9 pod replicas in namespace 'kube-system', 7 are Running and Ready.
I0117 14:09:29.264] Jan 17 14:09:29.263: INFO: POD                                 NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:29.265] Jan 17 14:09:29.263: INFO: coredns-557dcdc9f5-qtrkl            test-9b5ed62f1f-minion-group-x4ph  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:29.266] Jan 17 14:09:29.263: INFO: l7-default-backend-84c9fcfbb-np9rs  test-9b5ed62f1f-minion-group-x4ph  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [default-http-backend]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:29.266] Jan 17 14:09:29.263: INFO: 
I0117 14:09:31.262] Jan 17 14:09:31.262: INFO: The status of Pod coredns-557dcdc9f5-qtrkl is Running (Ready = false), waiting for it to be either Running (with Ready = true) or Failed
I0117 14:09:31.262] Jan 17 14:09:31.262: INFO: 27 / 28 pods in namespace 'kube-system' are running and ready (20 seconds elapsed)
I0117 14:09:31.263] Jan 17 14:09:31.262: INFO: expected 9 pod replicas in namespace 'kube-system', 8 are Running and Ready.
I0117 14:09:31.263] Jan 17 14:09:31.262: INFO: POD                       NODE                               PHASE    GRACE  CONDITIONS
I0117 14:09:31.264] Jan 17 14:09:31.262: INFO: coredns-557dcdc9f5-qtrkl  test-9b5ed62f1f-minion-group-x4ph  Running         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC ContainersNotReady containers with unready status: [coredns]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2020-01-17 14:09:15 +0000 UTC  }]
I0117 14:09:31.264] Jan 17 14:09:31.262: INFO: 
I0117 14:09:33.260] Jan 17 14:09:33.259: INFO: 28 / 28 pods in namespace 'kube-system' are running and ready (22 seconds elapsed)
... skipping 216 lines ...
I0117 14:10:19.327] 
I0117 14:10:19.327]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 14:10:19.328] ------------------------------
I0117 14:10:19.328] SS
I0117 14:10:19.328] ------------------------------
I0117 14:10:19.328] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Dynamic PV (default fs)] subPath 
I0117 14:10:19.329]   should fail if subpath directory is outside the volume [Slow]
I0117 14:10:19.329]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:216
I0117 14:10:19.329] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 14:10:19.329]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 14:10:19.329] [BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
I0117 14:10:19.330]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 14:10:19.330] STEP: Creating a kubernetes client
I0117 14:10:19.330] Jan 17 14:10:19.305: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 14:10:19.330] STEP: Building a namespace api object, basename provisioning
I0117 14:10:19.451] STEP: Waiting for a default service account to be provisioned in namespace
I0117 14:10:19.492] [It] should fail if subpath directory is outside the volume [Slow]
I0117 14:10:19.492]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:216
I0117 14:10:19.492] STEP: deploying csi gce-pd driver
I0117 14:10:19.538] Jan 17 14:10:19.535: INFO: Found CI service account key at /etc/service-account/service-account.json
I0117 14:10:19.538] Jan 17 14:10:19.535: INFO: Running cp [/etc/service-account/service-account.json /tmp/4e2c49b1-debb-40a4-b707-42fc76b517bd/cloud-sa.json]
I0117 14:10:19.590] Jan 17 14:10:19.588: INFO: Shredding file /tmp/4e2c49b1-debb-40a4-b707-42fc76b517bd/cloud-sa.json
I0117 14:10:19.593] Jan 17 14:10:19.588: INFO: Running shred [--remove /tmp/4e2c49b1-debb-40a4-b707-42fc76b517bd/cloud-sa.json]
... skipping 24 lines ...
I0117 14:10:20.602] Jan 17 14:10:20.601: INFO: creating *v1.StatefulSet: provisioning-9915/csi-gce-pd-controller
I0117 14:10:20.668] Jan 17 14:10:20.667: INFO: Test running for native CSI Driver, not checking metrics
I0117 14:10:20.668] Jan 17 14:10:20.667: INFO: Creating resource for dynamic PV
I0117 14:10:20.669] STEP: creating a StorageClass provisioning-9915-pd.csi.storage.gke.io-scxb4tn
I0117 14:10:20.764] STEP: creating a claim
I0117 14:10:20.875] STEP: Creating pod pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-rplx
I0117 14:10:20.951] STEP: Checking for subpath error in container status
I0117 14:12:59.018] Jan 17 14:12:59.015: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-rplx" in namespace "provisioning-9915"
I0117 14:12:59.063] Jan 17 14:12:59.063: INFO: Wait up to 5m0s for pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-rplx" to be fully deleted
I0117 14:13:11.158] STEP: Deleting pod
I0117 14:13:11.159] Jan 17 14:13:11.155: INFO: Deleting pod "pod-subpath-test-pd-csi-storage-gke-io-dynamicpv-rplx" in namespace "provisioning-9915"
I0117 14:13:11.200] STEP: Deleting pvc
I0117 14:13:11.200] Jan 17 14:13:11.199: INFO: Deleting PersistentVolumeClaim "pvc-62554"
... skipping 218 lines ...
I0117 14:18:12.175] 
I0117 14:18:12.175]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 14:18:12.175] ------------------------------
I0117 14:18:12.176] S
I0117 14:18:12.176] ------------------------------
I0117 14:18:12.176] [sig-storage] In-tree Volumes [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 14:18:12.176]   should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 14:18:12.177]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 14:18:12.177] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:18:12.177]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 14:18:12.177] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:18:12.178]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 14:18:12.178] STEP: Creating a kubernetes client
I0117 14:18:12.178] Jan 17 14:18:12.150: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 14:18:12.178] STEP: Building a namespace api object, basename provisioning
I0117 14:18:12.308] STEP: Waiting for a default service account to be provisioned in namespace
I0117 14:18:12.353] [It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
I0117 14:18:12.353]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 14:18:14.540] Jan 17 14:18:14.539: INFO: Running '/workspace/kubernetes/platforms/linux/amd64/kubectl --server=https://35.230.109.225 --kubeconfig=/workspace/.kube/config exec --namespace=provisioning-6674 hostexec-test-9b5ed62f1f-minion-group-s301 -- nsenter --mount=/rootfs/proc/1/ns/mnt -- sh -c ls -1 /mnt/disks/by-uuid/google-local-ssds-scsi-fs/ | wc -l'
I0117 14:18:15.943] Jan 17 14:18:15.939: INFO: stderr: "ls: cannot access '/mnt/disks/by-uuid/google-local-ssds-scsi-fs/': No such file or directory\n"
I0117 14:18:15.944] Jan 17 14:18:15.939: INFO: stdout: "0\n"
I0117 14:18:15.944] Jan 17 14:18:15.939: INFO: Requires at least 1 scsi fs localSSD 
I0117 14:18:15.944] [AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 7 lines ...
I0117 14:18:23.806] [sig-storage] In-tree Volumes
I0117 14:18:23.806] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 14:18:23.806]   [Driver: local][LocalVolumeType: gce-localssd-scsi-fs] [Serial]
I0117 14:18:23.806]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/in_tree_volumes.go:66
I0117 14:18:23.806]     [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 14:18:23.807]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 14:18:23.807]       should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [It]
I0117 14:18:23.807]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:243
I0117 14:18:23.808] 
I0117 14:18:23.808]       Requires at least 1 scsi fs localSSD 
I0117 14:18:23.808] 
I0117 14:18:23.808]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/drivers/in_tree.go:1720
I0117 14:18:23.808] ------------------------------
... skipping 2673 lines ...
I0117 15:05:58.752] 
I0117 15:05:58.752]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 15:05:58.752] ------------------------------
I0117 15:05:58.752] SSSSSSSSSSSSSSSSSSSSSSS
I0117 15:05:58.753] ------------------------------
I0117 15:05:58.753] [sig-storage] CSI Volumes CSI Topology test using GCE PD driver [Serial] 
I0117 15:05:58.753]   should fail to schedule a pod with a zone missing from AllowedTopologies; PD is provisioned with delayed volume binding
I0117 15:05:58.753]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:103
I0117 15:05:58.753] [BeforeEach] CSI Topology test using GCE PD driver [Serial]
I0117 15:05:58.754]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0117 15:05:58.754] STEP: Creating a kubernetes client
I0117 15:05:58.754] Jan 17 15:05:58.740: INFO: >>> kubeConfig: /workspace/.kube/config
I0117 15:05:58.754] STEP: Building a namespace api object, basename csitopology
... skipping 27 lines ...
I0117 15:05:59.711] Jan 17 15:05:59.711: INFO: creating *v1.RoleBinding: csitopology-4788/csi-controller-attacher-role-cfg
I0117 15:05:59.756] Jan 17 15:05:59.756: INFO: creating *v1.ClusterRoleBinding: csi-controller-provisioner-role-csitopology-4788
I0117 15:05:59.801] Jan 17 15:05:59.800: INFO: creating *v1.RoleBinding: csitopology-4788/csi-controller-provisioner-role-cfg
I0117 15:05:59.844] Jan 17 15:05:59.844: INFO: creating *v1.ClusterRoleBinding: psp-csi-controller-driver-registrar-role-csitopology-4788
I0117 15:05:59.888] Jan 17 15:05:59.888: INFO: creating *v1.DaemonSet: csitopology-4788/csi-gce-pd-node
I0117 15:05:59.937] Jan 17 15:05:59.937: INFO: creating *v1.StatefulSet: csitopology-4788/csi-gce-pd-controller
I0117 15:06:00.038] [It] should fail to schedule a pod with a zone missing from AllowedTopologies; PD is provisioned with delayed volume binding
I0117 15:06:00.038]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:103
I0117 15:06:00.117] Jan 17 15:06:00.117: INFO: Requires more than one zone
I0117 15:06:00.118] [AfterEach] CSI Topology test using GCE PD driver [Serial]
I0117 15:06:00.118]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
I0117 15:06:00.118] Jan 17 15:06:00.117: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0117 15:06:00.169] STEP: Destroying namespace "csitopology-4788" for this suite.
... skipping 26 lines ...
I0117 15:06:24.831] 
I0117 15:06:24.831] S [SKIPPING] [26.090 seconds]
I0117 15:06:24.832] [sig-storage] CSI Volumes
I0117 15:06:24.832] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 15:06:24.832]   CSI Topology test using GCE PD driver [Serial]
I0117 15:06:24.832]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:64
I0117 15:06:24.833]     should fail to schedule a pod with a zone missing from AllowedTopologies; PD is provisioned with delayed volume binding [It]
I0117 15:06:24.833]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:103
I0117 15:06:24.833] 
I0117 15:06:24.833]     Requires more than one zone
I0117 15:06:24.833] 
I0117 15:06:24.834]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:104
I0117 15:06:24.834] ------------------------------
... skipping 688 lines ...
I0117 15:14:13.113] 
I0117 15:14:13.113]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/drivers/in_tree.go:1720
I0117 15:14:13.114] ------------------------------
I0117 15:14:13.114] SSSSS
I0117 15:14:13.114] ------------------------------
I0117 15:14:13.115] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath 
I0117 15:14:13.115]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 15:14:13.115]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 15:14:13.115] [BeforeEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 15:14:13.116]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 15:14:13.116] Jan 17 15:14:13.110: INFO: Driver pd.csi.storage.gke.io doesn't support ntfs -- skipping
I0117 15:14:13.116] [AfterEach] [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 15:14:13.116]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 15:14:13.117] [sig-storage] CSI Volumes
I0117 15:14:13.117] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 15:14:13.117]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 15:14:13.117]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 15:14:13.118]     [Testpattern: Dynamic PV (ntfs)][sig-windows] subPath
I0117 15:14:13.118]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 15:14:13.118]       should fail if subpath with backstepping is outside the volume [Slow] [BeforeEach]
I0117 15:14:13.119]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 15:14:13.119] 
I0117 15:14:13.119]       Driver pd.csi.storage.gke.io doesn't support ntfs -- skipping
I0117 15:14:13.119] 
I0117 15:14:13.119]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:147
I0117 15:14:13.119] ------------------------------
... skipping 238 lines ...
I0117 15:16:01.424] STEP: Destroying namespace "downward-api-323" for this suite.
I0117 15:16:07.558] Jan 17 15:16:07.555: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
I0117 15:16:09.193] Jan 17 15:16:09.192: INFO: namespace downward-api-323 deletion completed in 7.768622408s
I0117 15:16:09.193] •SSSSSSSSSSSSSSS
I0117 15:16:09.194] ------------------------------
I0117 15:16:09.194] [sig-storage] CSI Volumes [Driver: pd.csi.storage.gke.io][Serial] [Testpattern: Pre-provisioned PV (default fs)] subPath 
I0117 15:16:09.194]   should fail if subpath with backstepping is outside the volume [Slow]
I0117 15:16:09.194]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 15:16:09.194] [BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 15:16:09.195]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:92
I0117 15:16:09.195] Jan 17 15:16:09.193: INFO: Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 15:16:09.195] [AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 15:16:09.196]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:151
... skipping 3 lines ...
I0117 15:16:09.196] [sig-storage] CSI Volumes
I0117 15:16:09.196] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/utils/framework.go:22
I0117 15:16:09.197]   [Driver: pd.csi.storage.gke.io][Serial]
I0117 15:16:09.197]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/csi_volumes.go:58
I0117 15:16:09.197]     [Testpattern: Pre-provisioned PV (default fs)] subPath
I0117 15:16:09.197]     /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:91
I0117 15:16:09.197]       should fail if subpath with backstepping is outside the volume [Slow] [BeforeEach]
I0117 15:16:09.198]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:254
I0117 15:16:09.198] 
I0117 15:16:09.198]       Driver pd.csi.storage.gke.io doesn't support PreprovisionedPV -- skipping
I0117 15:16:09.198] 
I0117 15:16:09.199]       /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/testsuites/base.go:142
I0117 15:16:09.199] ------------------------------
... skipping 690 lines ...
I0117 15:21:07.937] I0117 15:21:07.936583    8460 runners.go:180] daemonrestart10-c7826b7e-a41d-4931-948c-30036e3f82a1 Pods: 10 out of 10 created, 10 running, 0 pending, 0 waiting, 0 inactive, 0 terminating, 0 unknown, 0 runningButNotReady 
I0117 15:21:07.937] [It] Kubelet should not restart containers across restart
I0117 15:21:07.937]   /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/apps/daemon_restart.go:299
I0117 15:21:08.024] Jan 17 15:21:08.024: INFO: Checking if Daemon kubelet on node 35.247.88.15 is up by polling for a 200 on its /healthz endpoint
I0117 15:21:13.521] Jan 17 15:21:13.520: