This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultNot Finished
Started2019-05-19 22:17
Revision
Buildergke-prow-containerd-pool-99179761-xnlh
links{u'resultstore': {u'url': u'https://source.cloud.google.com/results/invocations/6f52c6a1-61b6-4996-a496-8bb9c2a6c3df/targets/test'}}
podbb96e4a6-7a83-11e9-9444-660052217703
resultstorehttps://source.cloud.google.com/results/invocations/6f52c6a1-61b6-4996-a496-8bb9c2a6c3df/targets/test

Test Failures


Node Tests 9m54s

error during go run /go/src/k8s.io/kubernetes/test/e2e_node/runner/remote/run_remote.go --cleanup --logtostderr --vmodule=*=4 --ssh-env=gce --results-dir=/workspace/_artifacts --project=k8s-jkns-ci-node-e2e --zone=us-west1-b --ssh-user=prow --ssh-key=/workspace/.ssh/google_compute_engine --ginkgo-flags=--nodes=8 --focus="\[NodeFeature:.+\]" --skip="\[Flaky\]|\[Serial\]" --test_args=--kubelet-flags="--cgroups-per-qos=true --cgroup-root=/" --test-timeout=1h5m0s --image-config-file=/workspace/test-infra/jobs/e2e_node/image-config.yaml: exit status 1
				from junit_runner.xml

Filter through log files | View test history on testgrid


Show 78 Passed Tests

Show 439 Skipped Tests

Error lines from build-log.txt

... skipping 293 lines ...
W0519 22:23:11.574] I0519 22:23:11.574330    4318 utils.go:117] Killing any existing node processes on "tmp-node-e2e-0f27b276-ubuntu-gke-1804-d1703-0-v20181113"
W0519 22:23:11.799] I0519 22:23:11.799634    4318 node_e2e.go:91] GCI/COS node and GCI/COS mounter both detected, modifying --experimental-mounter-path accordingly
W0519 22:23:11.800] I0519 22:23:11.799667    4318 node_e2e.go:147] Starting tests on "tmp-node-e2e-0f27b276-cos-stable-63-10032-71-0"
W0519 22:23:11.808] I0519 22:23:11.807846    4318 node_e2e.go:91] GCI/COS node and GCI/COS mounter both detected, modifying --experimental-mounter-path accordingly
W0519 22:23:11.808] I0519 22:23:11.807903    4318 node_e2e.go:147] Starting tests on "tmp-node-e2e-0f27b276-cos-stable-60-9592-84-0"
W0519 22:23:13.043] I0519 22:23:13.043006    4318 node_e2e.go:147] Starting tests on "tmp-node-e2e-0f27b276-ubuntu-gke-1804-d1703-0-v20181113"
W0519 22:27:42.201] I0519 22:27:42.201073    4318 remote.go:197] Test failed unexpectedly. Attempting to retrieving system logs (only works for nodes with journald)
W0519 22:27:43.202] I0519 22:27:43.201810    4318 remote.go:202] Got the system logs from journald; copying it back...
W0519 22:27:44.207] I0519 22:27:44.206782    4318 remote.go:122] Copying test artifacts from "tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911"
W0519 22:27:48.002] I0519 22:27:48.002419    4318 remote.go:122] Copying test artifacts from "tmp-node-e2e-0f27b276-cos-stable-60-9592-84-0"
W0519 22:27:48.596] I0519 22:27:48.596244    4318 run_remote.go:718] Deleting instance "tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911"
I0519 22:27:49.090] 
I0519 22:27:49.090] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
... skipping 92 lines ...
I0519 22:27:49.103] May 19 22:24:32.092: INFO: Skipping waiting for service account
I0519 22:27:49.103] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.103]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:49.103] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0519 22:27:49.103]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0519 22:27:49.103] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0519 22:27:49.104] STEP: Watching for error events or started pod
I0519 22:27:49.104] STEP: Checking that the pod was rejected
I0519 22:27:49.104] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.104]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:49.104] May 19 22:24:36.234: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0519 22:27:49.104] STEP: Destroying namespace "sysctl-5010" for this suite.
I0519 22:27:49.104] May 19 22:24:42.245: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 504 lines ...
I0519 22:27:49.168] May 19 22:25:03.708: INFO: Skipping waiting for service account
I0519 22:27:49.168] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.169]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:49.169] [It] should support sysctls
I0519 22:27:49.169]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0519 22:27:49.169] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:49.169] STEP: Watching for error events or started pod
I0519 22:27:49.169] STEP: Waiting for pod completion
I0519 22:27:49.169] STEP: Checking that the pod succeeded
I0519 22:27:49.169] STEP: Getting logs from the pod
I0519 22:27:49.169] STEP: Checking that the sysctl is actually updated
I0519 22:27:49.170] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.170]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 18 lines ...
I0519 22:27:49.172] May 19 22:25:12.649: INFO: Skipping waiting for service account
I0519 22:27:49.172] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.172]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:49.172] [It] should support unsafe sysctls which are actually whitelisted
I0519 22:27:49.172]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0519 22:27:49.172] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:49.172] STEP: Watching for error events or started pod
I0519 22:27:49.173] STEP: Waiting for pod completion
I0519 22:27:49.173] STEP: Checking that the pod succeeded
I0519 22:27:49.173] STEP: Getting logs from the pod
I0519 22:27:49.173] STEP: Checking that the sysctl is actually updated
I0519 22:27:49.173] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:49.173]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 617 lines ...
I0519 22:27:49.259] STEP: Wait for 0 temp events generated
I0519 22:27:49.259] STEP: Wait for 0 total events generated
I0519 22:27:49.259] STEP: Make sure only 0 total events generated
I0519 22:27:49.260] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:49.260] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:49.260] STEP: should not generate events for too old log
I0519 22:27:49.260] STEP: Inject 3 logs: "temporary error"
I0519 22:27:49.260] STEP: Wait for 0 temp events generated
I0519 22:27:49.260] STEP: Wait for 0 total events generated
I0519 22:27:49.260] STEP: Make sure only 0 total events generated
I0519 22:27:49.261] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:49.261] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:49.261] STEP: should not change node condition for too old log
I0519 22:27:49.261] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:49.261] STEP: Wait for 0 temp events generated
I0519 22:27:49.261] STEP: Wait for 0 total events generated
I0519 22:27:49.262] STEP: Make sure only 0 total events generated
I0519 22:27:49.262] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:49.262] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:49.262] STEP: should generate event for old log within lookback duration
I0519 22:27:49.262] STEP: Inject 3 logs: "temporary error"
I0519 22:27:49.262] STEP: Wait for 3 temp events generated
I0519 22:27:49.262] STEP: Wait for 3 total events generated
I0519 22:27:49.263] STEP: Make sure only 3 total events generated
I0519 22:27:49.263] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:49.263] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:49.263] STEP: should change node condition for old log within lookback duration
I0519 22:27:49.263] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:49.263] STEP: Wait for 3 temp events generated
I0519 22:27:49.264] STEP: Wait for 4 total events generated
I0519 22:27:49.264] [AfterEach] [k8s.io] SystemLogMonitor
I0519 22:27:49.264]   _output/local/go/src/k8s.io/kubernetes/test/e2e_node/node_problem_detector_linux.go:368
I0519 22:27:49.264] STEP: Get node problem detector log
I0519 22:27:49.264] May 19 22:26:17.320: INFO: Node Problem Detector logs:
I0519 22:27:49.265]  I0519 22:24:35.149148       7 log_monitor.go:64] Finish parsing log monitor config file: {WatcherConfig:{Plugin:filelog PluginConfig:map[timestamp:^.{15} message:kernel: \[.*\] (.*) timestampFormat:Jan _2 15:04:05] LogPath:/log/test.log Lookback:1h5m40.065463325s Delay:} BufferSize:10 Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 DefaultConditions:[{Type:TestCondition Status: Transition:0001-01-01 00:00:00 +0000 UTC Reason:Default Message:default message}] Rules:[{Type:temporary Condition: Reason:Temporary Pattern:temporary error} {Type:permanent Condition:TestCondition Reason:Permanent1 Pattern:permanent error 1.*} {Type:permanent Condition:TestCondition Reason:Permanent2 Pattern:permanent error 2.*}]}
I0519 22:27:49.265] I0519 22:24:35.149512       7 log_watchers.go:40] Use log watcher of plugin "filelog"
I0519 22:27:49.265] I0519 22:24:35.153638       7 log_monitor.go:73] Start log monitor
I0519 22:27:49.265] I0519 22:24:35.153721       7 log_watcher.go:83] Start watching filelog
I0519 22:27:49.265] I0519 22:24:35.153735       7 problem_detector.go:73] Problem detector started
I0519 22:27:49.266] I0519 22:24:35.175808       7 log_monitor.go:170] Initialize condition generated: [{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]
I0519 22:27:49.266] I0519 22:25:06.704045       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.267] I0519 22:25:06.704201       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.267] I0519 22:25:06.704272       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.267] I0519 22:25:17.711691       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.268] I0519 22:25:17.711791       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.268] I0519 22:25:17.711863       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:warn Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Temporary Message:temporary error}] Conditions:[{Type:TestCondition Status:False Transition:2019-05-19 22:24:35.175789591 +0000 UTC m=+0.215714878 Reason:Default Message:default message}]}
I0519 22:27:49.268] I0519 22:25:17.711940       7 log_monitor.go:115] New status generated: &{Source:kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 Events:[{Severity:info Timestamp:2019-05-19 22:24:32 +0000 UTC Reason:Permanent1 Message:Node condition TestCondition is now: True, reason: Permanent1}] Conditions:[{Type:TestCondition Status:True Transition:2019-05-19 22:24:32 +0000 UTC Reason:Permanent1 Message:permanent error 1}]}
I0519 22:27:49.268] 
I0519 22:27:49.269] STEP: Delete the node problem detector
I0519 22:27:49.269] STEP: Wait for the node problem detector to disappear
I0519 22:27:49.269] May 19 22:26:17.342: INFO: Waiting for pod node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338 to disappear
I0519 22:27:49.269] May 19 22:26:17.381: INFO: Pod node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338 no longer exists
I0519 22:27:49.269] STEP: Delete the config map
... skipping 8 lines ...
I0519 22:27:49.271] May 19 22:26:17.398: INFO: At 2019-05-19 22:24:35 +0000 UTC - event for node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338: {kubelet tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} Started: Started container node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338
I0519 22:27:49.271] May 19 22:26:17.398: INFO: At 2019-05-19 22:26:17 +0000 UTC - event for node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338: {kubelet tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} Killing: Stopping container node-problem-detector-22c968ab-7d30-4834-a4c3-7ac5e71c4338
I0519 22:27:49.272] May 19 22:26:17.399: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
I0519 22:27:49.272] May 19 22:26:17.399: INFO: 
I0519 22:27:49.272] May 19 22:26:17.401: INFO: 
I0519 22:27:49.272] Logging node info for node tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911
I0519 22:27:49.276] May 19 22:26:17.403: INFO: Node Info: &Node{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911,GenerateName:,Namespace:,SelfLink:/api/v1/nodes/tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911,UID:fbfc582c-8b28-4195-bd34-f20ca1200414,ResourceVersion:652,Generation:0,CreationTimestamp:2019-05-19 22:24:30 +0000 UTC,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{beta.kubernetes.io/arch: amd64,beta.kubernetes.io/os: linux,kubernetes.io/arch: amd64,kubernetes.io/hostname: tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911,kubernetes.io/os: linux,},Annotations:map[string]string{volumes.kubernetes.io/controller-managed-attach-detach: true,},OwnerReferences:[],Finalizers:[],ClusterName:,Initializers:nil,ManagedFields:[],},Spec:NodeSpec{PodCIDR:,DoNotUse_ExternalID:,ProviderID:,Unschedulable:false,Taints:[],ConfigSource:nil,},Status:NodeStatus{Capacity:ResourceList{cpu: {{1 0} {<nil>} 1 DecimalSI},ephemeral-storage: {{18327040000 0} {<nil>} 17897500Ki BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{3875430400 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{cpu: {{1 0} {<nil>} 1 DecimalSI},ephemeral-storage: {{16494335973 0} {<nil>} 16494335973 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{3613286400 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[{MemoryPressure False 2019-05-19 22:25:31 +0000 UTC 2019-05-19 22:24:28 +0000 UTC KubeletHasSufficientMemory kubelet has sufficient memory available} {DiskPressure False 2019-05-19 22:25:31 +0000 UTC 2019-05-19 22:24:28 +0000 UTC KubeletHasNoDiskPressure kubelet has no disk pressure} {PIDPressure False 2019-05-19 22:25:31 +0000 UTC 2019-05-19 22:24:28 +0000 UTC KubeletHasSufficientPID kubelet has sufficient PID available} {Ready True 2019-05-19 22:25:31 +0000 UTC 2019-05-19 22:24:28 +0000 UTC KubeletReady kubelet is posting ready status}],Addresses:[{InternalIP 10.138.0.7} {Hostname tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911}],DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:af1d706df408c717b92f1f1ff50ef256,SystemUUID:AF1D706D-F408-C717-B92F-1F1FF50EF256,BootID:55415498-6ad8-4463-bf97-c3c9b0a881f2,KernelVersion:4.14.69-coreos,OSImage:Container Linux by CoreOS 1883.1.0 (Rhyolite),ContainerRuntimeVersion:docker://18.6.1,KubeletVersion:v1.15.0-beta.0.214+19e1375a042a0d,KubeProxyVersion:v1.15.0-beta.0.214+19e1375a042a0d,OperatingSystem:linux,Architecture:amd64,},Images:[{[gcr.io/kubernetes-e2e-test-images/node-perf/tf-wide-deep-amd64@sha256:80d4564d5ab49ecfea3b20f75cc676d8dfd8b2aca364ed4c1a8a55fbcaaed7f6 gcr.io/kubernetes-e2e-test-images/node-perf/tf-wide-deep-amd64:1.0] 634170972} {[gcr.io/kubernetes-e2e-test-images/volume/gluster@sha256:e2d3308b2d27499d59f120ff46dfc6c4cb307a3f207f02894ecab902583761c9 gcr.io/kubernetes-e2e-test-images/volume/gluster:1.0] 332011484} {[gcr.io/kubernetes-e2e-test-images/volume/nfs@sha256:c2ad734346f608a5f7d69cfded93c4e8094069320657bd372d12ba21dea3ea71 gcr.io/kubernetes-e2e-test-images/volume/nfs:1.0] 225358913} {[k8s.gcr.io/node-problem-detector@sha256:6e9b4a4eaa47f120be61f60573a545844de63401661812e2cfb7ae81a28efd19 k8s.gcr.io/node-problem-detector:v0.6.2] 98707739} {[gcr.io/kubernetes-e2e-test-images/node-perf/npb-is@sha256:9d08dd99565b25af37c990cd4474a4284b27e7ceb3f98328bb481edefedf8aa5 gcr.io/kubernetes-e2e-test-images/node-perf/npb-is:1.0] 96288249} {[gcr.io/kubernetes-e2e-test-images/node-perf/npb-ep@sha256:564314549347619cfcdbe6c7d042a29e133a00e922b37682890fff17ac1a7804 gcr.io/kubernetes-e2e-test-images/node-perf/npb-ep:1.0] 96286449} {[google/cadvisor@sha256:815386ebbe9a3490f38785ab11bda34ec8dacf4634af77b8912832d4f85dca04 google/cadvisor:latest] 69583040} {[k8s.gcr.io/nvidia-gpu-device-plugin@sha256:08509a36233c5096bb273a492251a9a5ca28558ab36d74007ca2a9d3f0b61e1d] 18976858} {[nginx@sha256:485b610fefec7ff6c463ced9623314a04ed67e3945b9c08d7e53a47f6d108dc7 nginx:1.14-alpine] 16032814} {[gcr.io/kubernetes-e2e-test-images/audit-proxy@sha256:9cf10c6bb871a9a2a45eb1634ecd36cf0e45ec9bd8ae05bf10bef981ac07cc1b gcr.io/kubernetes-e2e-test-images/audit-proxy:1.0] 13222979} {[gcr.io/kubernetes-e2e-test-images/net@sha256:973f47a88f50ccd7800f6ec300e664461e7c011c2da3a33edf32a73dd9ff9c01 gcr.io/kubernetes-e2e-test-images/net:1.0] 11393460} {[gcr.io/kubernetes-e2e-test-images/ipc-utils@sha256:bb127be3a1ecac0516f672a5e223d94fe6021021534ecb7a02a607a63154c3d8 gcr.io/kubernetes-e2e-test-images/ipc-utils:1.0] 10039224} {[gcr.io/kubernetes-e2e-test-images/hostexec@sha256:90dfe59da029f9e536385037bc64e86cd3d6e55bae613ddbe69e554d79b0639d gcr.io/kubernetes-e2e-test-images/hostexec:1.1] 8490662} {[gcr.io/kubernetes-e2e-test-images/nonewprivs@sha256:10066e9039219449fe3c81f38fe01928f87914150768ab81b62a468e51fa7411 gcr.io/kubernetes-e2e-test-images/nonewprivs:1.0] 6757579} {[gcr.io/kubernetes-e2e-test-images/netexec@sha256:203f0e11dde4baf4b08e27de094890eb3447d807c8b3e990b764b799d3a9e8b7 gcr.io/kubernetes-e2e-test-images/netexec:1.1] 6705349} {[gcr.io/kubernetes-e2e-test-images/serve-hostname@sha256:bab70473a6d8ef65a22625dc9a1b0f0452e811530fdbe77e4408523460177ff1 gcr.io/kubernetes-e2e-test-images/serve-hostname:1.1] 5851985} {[gcr.io/kubernetes-e2e-test-images/liveness@sha256:71c3fc838e0637df570497febafa0ee73bf47176dfd43612de5c55a71230674e gcr.io/kubernetes-e2e-test-images/liveness:1.1] 5829944} {[k8s.gcr.io/stress@sha256:f00aa1ddc963a3164aef741aab0fc05074ea96de6cd7e0d10077cf98dd72d594 k8s.gcr.io/stress:v1] 5494760} {[gcr.io/kubernetes-e2e-test-images/test-webserver@sha256:7f93d6e32798ff28bc6289254d0c2867fe2c849c8e46edc50f8624734309812e gcr.io/kubernetes-e2e-test-images/test-webserver:1.0] 4732240} {[gcr.io/kubernetes-e2e-test-images/entrypoint-tester@sha256:ba4681b5299884a3adca70fbde40638373b437a881055ffcd0935b5f43eb15c9 gcr.io/kubernetes-e2e-test-images/entrypoint-tester:1.0] 2729534} {[gcr.io/kubernetes-e2e-test-images/mounttest@sha256:c0bd6f0755f42af09a68c9a47fb993136588a76b3200ec305796b60d629d85d2 gcr.io/kubernetes-e2e-test-images/mounttest:1.0] 1563521} {[gcr.io/kubernetes-e2e-test-images/mounttest-user@sha256:17319ca525ee003681fccf7e8c6b1b910ff4f49b653d939ac7f9b6e7c463933d gcr.io/kubernetes-e2e-test-images/mounttest-user:1.0] 1450451} {[busybox@sha256:8ccbac733d19c0dd4d70b4f0c1e12245b5fa3ad24758a11035ee505c629c0796 busybox:1.29] 1154361} {[k8s.gcr.io/busybox@sha256:4bdd623e848417d96127e16037743f0cd8b528c026e9175e22a84f639eca58ff] 1113554} {[k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea k8s.gcr.io/pause:3.1] 742472}],VolumesInUse:[],VolumesAttached:[],Config:&NodeConfigStatus{Assigned:nil,Active:nil,LastKnownGood:nil,Error:,},},}
I0519 22:27:49.276] May 19 22:26:17.403: INFO: 
I0519 22:27:49.276] Logging kubelet events for node tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911
I0519 22:27:49.276] May 19 22:26:17.404: INFO: 
I0519 22:27:49.277] Logging pods the kubelet thinks is on node tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911
I0519 22:27:49.277] May 19 22:26:17.410: INFO: var-expansion-0469af42-b495-4d75-8f65-706f62c4dc96 started at 2019-05-19 22:24:32 +0000 UTC (1+1 container statuses recorded)
I0519 22:27:49.277] May 19 22:26:17.410: INFO: 	Init container init-volume-0469af42-b495-4d75-8f65-706f62c4dc96 ready: true, restart count 0
... skipping 21 lines ...
I0519 22:27:49.281]   [k8s.io] SystemLogMonitor
I0519 22:27:49.281]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:49.281]     should generate node condition and events for corresponding errors [It]
I0519 22:27:49.282]     _output/local/go/src/k8s.io/kubernetes/test/e2e_node/node_problem_detector_linux.go:245
I0519 22:27:49.282] 
I0519 22:27:49.282]     Timed out after 60.000s.
I0519 22:27:49.282]     Expected success, but got an error:
I0519 22:27:49.282]         <*errors.errorString | 0xc000df2860>: {
I0519 22:27:49.283]             s: "expect event number 4, got 7: [{{ } {tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035dfdef082b9  default /api/v1/namespaces/default/events/tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035dfdef082b9 a9cd3774-4ab9-45f4-9133-25841f975546 387 0 2019-05-19 22:25:06 +0000 UTC <nil> <nil> map[] map[] [] nil []  []} {Node  tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911   } Temporary temporary error {kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} 2019-05-19 22:25:06 +0000 UTC 2019-05-19 22:25:17 +0000 UTC 6 Warning 0001-01-01 00:00:00 +0000 UTC nil  nil  } {{ } {tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035e26f0e3d84  default /api/v1/namespaces/default/events/tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035e26f0e3d84 77b0567d-a7de-4316-9399-8d08610db607 386 0 2019-05-19 22:25:17 +0000 UTC <nil> <nil> map[] map[] [] nil []  []} {Node  tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911   } Permanent1 Node condition TestCondition is now: True, reason: Permanent1 {kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} 2019-05-19 22:25:17 +0000 UTC 2019-05-19 22:25:17 +0000 UTC 1 Normal 0001-01-01 00:00:00 +0000 UTC nil  nil  }]",
I0519 22:27:49.283]         }
I0519 22:27:49.284]         expect event number 4, got 7: [{{ } {tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035dfdef082b9  default /api/v1/namespaces/default/events/tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035dfdef082b9 a9cd3774-4ab9-45f4-9133-25841f975546 387 0 2019-05-19 22:25:06 +0000 UTC <nil> <nil> map[] map[] [] nil []  []} {Node  tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911   } Temporary temporary error {kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} 2019-05-19 22:25:06 +0000 UTC 2019-05-19 22:25:17 +0000 UTC 6 Warning 0001-01-01 00:00:00 +0000 UTC nil  nil  } {{ } {tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035e26f0e3d84  default /api/v1/namespaces/default/events/tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911.15a035e26f0e3d84 77b0567d-a7de-4316-9399-8d08610db607 386 0 2019-05-19 22:25:17 +0000 UTC <nil> <nil> map[] map[] [] nil []  []} {Node  tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911   } Permanent1 Node condition TestCondition is now: True, reason: Permanent1 {kernel-monitor-22c968ab-7d30-4834-a4c3-7ac5e71c4338 tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911} 2019-05-19 22:25:17 +0000 UTC 2019-05-19 22:25:17 +0000 UTC 1 Normal 0001-01-01 00:00:00 +0000 UTC nil  nil  }]
I0519 22:27:49.284] 
I0519 22:27:49.284]     _output/local/go/src/k8s.io/kubernetes/test/e2e_node/node_problem_detector_linux.go:351
I0519 22:27:49.285] ------------------------------
I0519 22:27:49.285] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:49.285]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:49.287] STEP: Creating a kubernetes client
... skipping 29 lines ...
I0519 22:27:49.293] ------------------------------
I0519 22:27:49.293] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:49.293]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:49.293] STEP: Creating a kubernetes client
I0519 22:27:49.293] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:49.294] May 19 22:25:04.802: INFO: Skipping waiting for service account
I0519 22:27:49.294] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:49.294]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:49.294] May 19 22:27:04.833: INFO: Deleting pod "var-expansion-8fd1f536-98c7-4493-b4ec-64be5d6a2e3e" in namespace "var-expansion-2771"
I0519 22:27:49.295] May 19 22:27:04.838: INFO: Wait up to 5m0s for pod "var-expansion-8fd1f536-98c7-4493-b4ec-64be5d6a2e3e" to be fully deleted
I0519 22:27:49.295] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:49.295]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:49.295] May 19 22:27:08.847: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:49.296] May 19 22:27:14.892: INFO: namespace var-expansion-2771 deletion completed in 6.043615296s
I0519 22:27:49.296] 
I0519 22:27:49.296] 
I0519 22:27:49.297] • [SLOW TEST:130.102 seconds]
I0519 22:27:49.297] [k8s.io] Variable Expansion
I0519 22:27:49.297] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:49.297]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:49.297]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:49.298] ------------------------------
I0519 22:27:49.298] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:49.298]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:49.298] STEP: Creating a kubernetes client
I0519 22:27:49.298] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:49.299] May 19 22:24:32.089: INFO: No PodSecurityPolicies found; assuming PodSecurityPolicy is disabled.
I0519 22:27:49.299] May 19 22:24:32.089: INFO: Skipping waiting for service account
I0519 22:27:49.299] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:49.299]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0519 22:27:49.300] STEP: creating the pod with failed condition
I0519 22:27:49.300] STEP: updating the pod
I0519 22:27:49.300] May 19 22:26:32.784: INFO: Successfully updated pod "var-expansion-58ee1a26-98bb-4546-bf35-c69dd8b9d2ee"
I0519 22:27:49.300] STEP: waiting for pod running
I0519 22:27:49.300] STEP: deleting the pod gracefully
I0519 22:27:49.301] May 19 22:26:34.790: INFO: Deleting pod "var-expansion-58ee1a26-98bb-4546-bf35-c69dd8b9d2ee" in namespace "var-expansion-5271"
I0519 22:27:49.301] May 19 22:26:34.798: INFO: Wait up to 5m0s for pod "var-expansion-58ee1a26-98bb-4546-bf35-c69dd8b9d2ee" to be fully deleted
... skipping 60 lines ...
I0519 22:27:49.313] ------------------------------
I0519 22:27:49.313] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:49.313]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:49.313] STEP: Creating a kubernetes client
I0519 22:27:49.314] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:49.314] May 19 22:25:33.878: INFO: Skipping waiting for service account
I0519 22:27:49.314] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:49.314]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:49.315] May 19 22:27:33.938: INFO: Deleting pod "var-expansion-be5224a9-2478-4e88-b67d-31504e2266fd" in namespace "var-expansion-6672"
I0519 22:27:49.315] May 19 22:27:33.941: INFO: Wait up to 5m0s for pod "var-expansion-be5224a9-2478-4e88-b67d-31504e2266fd" to be fully deleted
I0519 22:27:49.315] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:49.315]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:49.315] May 19 22:27:35.949: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:49.316] May 19 22:27:42.006: INFO: namespace var-expansion-6672 deletion completed in 6.055040701s
I0519 22:27:49.316] 
I0519 22:27:49.316] 
I0519 22:27:49.316] • [SLOW TEST:128.131 seconds]
I0519 22:27:49.317] [k8s.io] Variable Expansion
I0519 22:27:49.317] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:49.317]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:49.317]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:49.317] ------------------------------
I0519 22:27:49.317] I0519 22:27:42.020531    1340 e2e_node_suite_test.go:186] Stopping node services...
I0519 22:27:49.318] I0519 22:27:42.020560    1340 server.go:257] Kill server "services"
I0519 22:27:49.318] I0519 22:27:42.020568    1340 server.go:294] Killing process 2114 (services) with -TERM
I0519 22:27:49.318] E0519 22:27:42.077280    1340 services.go:89] Failed to stop services: error stopping "services": waitid: no child processes
I0519 22:27:49.318] I0519 22:27:42.077298    1340 server.go:257] Kill server "kubelet"
I0519 22:27:49.318] I0519 22:27:42.088483    1340 services.go:148] Fetching log files...
I0519 22:27:49.319] I0519 22:27:42.088547    1340 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0519 22:27:49.319] I0519 22:27:42.118300    1340 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0519 22:27:49.319] E0519 22:27:42.122731    1340 services.go:160] failed to get "cloud-init.log" from journald: Failed to add filter for units: No data available
I0519 22:27:49.319] , exit status 1
I0519 22:27:49.319] I0519 22:27:42.122765    1340 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0519 22:27:49.319] I0519 22:27:42.128445    1340 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190519T222259.service].
I0519 22:27:49.320] I0519 22:27:42.144301    1340 e2e_node_suite_test.go:191] Tests Finished
I0519 22:27:49.320] 
I0519 22:27:49.320] 
I0519 22:27:49.320] 
I0519 22:27:49.320] Summarizing 1 Failure:
I0519 22:27:49.320] 
I0519 22:27:49.321] [Fail] [k8s.io] NodeProblemDetector [NodeFeature:NodeProblemDetector] [k8s.io] SystemLogMonitor [It] should generate node condition and events for corresponding errors 
I0519 22:27:49.321] _output/local/go/src/k8s.io/kubernetes/test/e2e_node/node_problem_detector_linux.go:351
I0519 22:27:49.321] 
I0519 22:27:49.321] Ran 37 of 301 Specs in 268.728 seconds
I0519 22:27:49.321] FAIL! -- 36 Passed | 1 Failed | 0 Pending | 264 Skipped
I0519 22:27:49.321] 
I0519 22:27:49.321] 
I0519 22:27:49.322] Ginkgo ran 1 suite in 4m30.576420336s
I0519 22:27:49.322] Test Suite Failed
I0519 22:27:49.322] 
I0519 22:27:49.322] Failure Finished Test Suite on Host tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911
I0519 22:27:49.323] command [ssh -o UserKnownHostsFile=/dev/null -o IdentitiesOnly=yes -o CheckHostIP=no -o StrictHostKeyChecking=no -o ServerAliveInterval=30 -o LogLevel=ERROR -i /workspace/.ssh/google_compute_engine prow@35.247.81.6 -- sudo sh -c 'cd /tmp/node-e2e-20190519T222259 && timeout -k 30s 3900.000000s ./ginkgo --nodes=8 --focus="\[NodeFeature:.+\]" --skip="\[Flaky\]|\[Serial\]" ./e2e_node.test -- --system-spec-name= --system-spec-file= --extra-envs= --logtostderr --v 4 --node-name=tmp-node-e2e-0f27b276-coreos-beta-1883-1-0-v20180911 --report-dir=/tmp/node-e2e-20190519T222259/results --report-prefix=coreos-beta --image-description="coreos-beta-1883-1-0-v20180911" --kubelet-flags="--cgroups-per-qos=true --cgroup-root=/"'] failed with error: exit status 1
I0519 22:27:49.323] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
I0519 22:27:49.323] <                              FINISH TEST                               <
I0519 22:27:49.323] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
I0519 22:27:49.323] 
W0519 22:27:51.915] I0519 22:27:51.914848    4318 remote.go:122] Copying test artifacts from "tmp-node-e2e-0f27b276-cos-stable-63-10032-71-0"
W0519 22:27:52.609] I0519 22:27:52.609738    4318 run_remote.go:718] Deleting instance "tmp-node-e2e-0f27b276-cos-stable-60-9592-84-0"
... skipping 523 lines ...
I0519 22:27:53.106] May 19 22:24:39.913: INFO: Skipping waiting for service account
I0519 22:27:53.106] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.106]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:53.106] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0519 22:27:53.107]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0519 22:27:53.107] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0519 22:27:53.107] STEP: Watching for error events or started pod
I0519 22:27:53.107] STEP: Checking that the pod was rejected
I0519 22:27:53.107] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.107]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:53.107] May 19 22:24:42.042: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0519 22:27:53.107] STEP: Destroying namespace "sysctl-2924" for this suite.
I0519 22:27:53.108] May 19 22:24:48.066: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 279 lines ...
I0519 22:27:53.140] May 19 22:25:15.931: INFO: Skipping waiting for service account
I0519 22:27:53.140] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.141]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:53.141] [It] should support sysctls
I0519 22:27:53.141]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0519 22:27:53.141] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:53.141] STEP: Watching for error events or started pod
I0519 22:27:53.141] STEP: Waiting for pod completion
I0519 22:27:53.141] STEP: Checking that the pod succeeded
I0519 22:27:53.141] STEP: Getting logs from the pod
I0519 22:27:53.141] STEP: Checking that the sysctl is actually updated
I0519 22:27:53.141] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.142]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 470 lines ...
I0519 22:27:53.194] May 19 22:26:04.441: INFO: Skipping waiting for service account
I0519 22:27:53.194] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.194]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:53.194] [It] should support unsafe sysctls which are actually whitelisted
I0519 22:27:53.195]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0519 22:27:53.195] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:53.195] STEP: Watching for error events or started pod
I0519 22:27:53.195] STEP: Waiting for pod completion
I0519 22:27:53.195] STEP: Checking that the pod succeeded
I0519 22:27:53.195] STEP: Getting logs from the pod
I0519 22:27:53.195] STEP: Checking that the sysctl is actually updated
I0519 22:27:53.195] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:53.195]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 64 lines ...
I0519 22:27:53.203] STEP: Wait for 0 temp events generated
I0519 22:27:53.203] STEP: Wait for 0 total events generated
I0519 22:27:53.203] STEP: Make sure only 0 total events generated
I0519 22:27:53.203] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.204] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.204] STEP: should not generate events for too old log
I0519 22:27:53.204] STEP: Inject 3 logs: "temporary error"
I0519 22:27:53.204] STEP: Wait for 0 temp events generated
I0519 22:27:53.204] STEP: Wait for 0 total events generated
I0519 22:27:53.204] STEP: Make sure only 0 total events generated
I0519 22:27:53.204] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.204] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.204] STEP: should not change node condition for too old log
I0519 22:27:53.204] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:53.204] STEP: Wait for 0 temp events generated
I0519 22:27:53.205] STEP: Wait for 0 total events generated
I0519 22:27:53.205] STEP: Make sure only 0 total events generated
I0519 22:27:53.205] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.205] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.205] STEP: should generate event for old log within lookback duration
I0519 22:27:53.205] STEP: Inject 3 logs: "temporary error"
I0519 22:27:53.205] STEP: Wait for 3 temp events generated
I0519 22:27:53.205] STEP: Wait for 3 total events generated
I0519 22:27:53.206] STEP: Make sure only 3 total events generated
I0519 22:27:53.206] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.206] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.206] STEP: should change node condition for old log within lookback duration
I0519 22:27:53.206] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:53.206] STEP: Wait for 3 temp events generated
I0519 22:27:53.206] STEP: Wait for 4 total events generated
I0519 22:27:53.206] STEP: Make sure only 4 total events generated
I0519 22:27:53.206] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.206] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.207] STEP: should generate event for new log
I0519 22:27:53.207] STEP: Inject 3 logs: "temporary error"
I0519 22:27:53.207] STEP: Wait for 6 temp events generated
I0519 22:27:53.207] STEP: Wait for 7 total events generated
I0519 22:27:53.207] STEP: Make sure only 7 total events generated
I0519 22:27:53.207] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.207] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.208] STEP: should not update node condition with the same reason
I0519 22:27:53.208] STEP: Inject 1 logs: "permanent error 1different message"
I0519 22:27:53.208] STEP: Wait for 6 temp events generated
I0519 22:27:53.208] STEP: Wait for 7 total events generated
I0519 22:27:53.208] STEP: Make sure only 7 total events generated
I0519 22:27:53.208] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.208] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.208] STEP: should change node condition for new log
I0519 22:27:53.209] STEP: Inject 1 logs: "permanent error 2"
I0519 22:27:53.209] STEP: Wait for 6 temp events generated
I0519 22:27:53.209] STEP: Wait for 8 total events generated
I0519 22:27:53.209] STEP: Make sure only 8 total events generated
I0519 22:27:53.209] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:53.209] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:53.209] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 23 lines ...
I0519 22:27:53.212] ------------------------------
I0519 22:27:53.212] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:53.212]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:53.212] STEP: Creating a kubernetes client
I0519 22:27:53.212] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:53.212] May 19 22:24:37.761: INFO: Skipping waiting for service account
I0519 22:27:53.213] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.213]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:53.213] May 19 22:26:37.884: INFO: Deleting pod "var-expansion-7119f6ff-7bc8-4bfe-8536-519cba2ad114" in namespace "var-expansion-4839"
I0519 22:27:53.213] May 19 22:26:37.888: INFO: Wait up to 5m0s for pod "var-expansion-7119f6ff-7bc8-4bfe-8536-519cba2ad114" to be fully deleted
I0519 22:27:53.213] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:53.213]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:53.213] May 19 22:26:41.896: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:53.214] May 19 22:26:47.945: INFO: namespace var-expansion-4839 deletion completed in 6.04760128s
I0519 22:27:53.214] 
I0519 22:27:53.214] 
I0519 22:27:53.214] • [SLOW TEST:130.191 seconds]
I0519 22:27:53.214] [k8s.io] Variable Expansion
I0519 22:27:53.214] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:53.214]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.214]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:53.214] ------------------------------
I0519 22:27:53.215] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:53.215]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:53.215] STEP: Creating a kubernetes client
I0519 22:27:53.215] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:53.215] May 19 22:24:51.720: INFO: Skipping waiting for service account
I0519 22:27:53.215] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.215]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:53.215] May 19 22:26:51.797: INFO: Deleting pod "var-expansion-45d433ed-1d7e-413f-ac4b-4814baa3ab46" in namespace "var-expansion-7456"
I0519 22:27:53.216] May 19 22:26:51.800: INFO: Wait up to 5m0s for pod "var-expansion-45d433ed-1d7e-413f-ac4b-4814baa3ab46" to be fully deleted
I0519 22:27:53.216] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:53.216]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:53.216] May 19 22:26:55.805: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:53.216] May 19 22:27:01.856: INFO: namespace var-expansion-7456 deletion completed in 6.049120513s
I0519 22:27:53.216] 
I0519 22:27:53.216] 
I0519 22:27:53.216] • [SLOW TEST:130.139 seconds]
I0519 22:27:53.217] [k8s.io] Variable Expansion
I0519 22:27:53.217] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:53.217]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.217]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:53.217] ------------------------------
I0519 22:27:53.217] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:53.217]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:53.217] STEP: Creating a kubernetes client
I0519 22:27:53.218] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:53.218] May 19 22:24:58.299: INFO: Skipping waiting for service account
I0519 22:27:53.218] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.218]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0519 22:27:53.218] STEP: creating the pod with failed condition
I0519 22:27:53.218] STEP: updating the pod
I0519 22:27:53.218] May 19 22:26:58.875: INFO: Successfully updated pod "var-expansion-33910958-6240-4854-9fbc-fcd4cd0161ac"
I0519 22:27:53.218] STEP: waiting for pod running
I0519 22:27:53.218] STEP: deleting the pod gracefully
I0519 22:27:53.219] May 19 22:27:00.940: INFO: Deleting pod "var-expansion-33910958-6240-4854-9fbc-fcd4cd0161ac" in namespace "var-expansion-2332"
I0519 22:27:53.219] May 19 22:27:00.945: INFO: Wait up to 5m0s for pod "var-expansion-33910958-6240-4854-9fbc-fcd4cd0161ac" to be fully deleted
... skipping 57 lines ...
I0519 22:27:53.226]   should not change the subpath mount on a container restart if the environment variable changes [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:53.226]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:519
I0519 22:27:53.226] ------------------------------
I0519 22:27:53.226] I0519 22:27:47.188434    1312 e2e_node_suite_test.go:186] Stopping node services...
I0519 22:27:53.226] I0519 22:27:47.188459    1312 server.go:257] Kill server "services"
I0519 22:27:53.226] I0519 22:27:47.188468    1312 server.go:294] Killing process 1844 (services) with -TERM
I0519 22:27:53.227] E0519 22:27:47.295728    1312 services.go:89] Failed to stop services: error stopping "services": waitid: no child processes
I0519 22:27:53.227] I0519 22:27:47.295747    1312 server.go:257] Kill server "kubelet"
I0519 22:27:53.227] I0519 22:27:47.304075    1312 services.go:148] Fetching log files...
I0519 22:27:53.227] I0519 22:27:47.304141    1312 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190519T222259.service].
I0519 22:27:53.227] I0519 22:27:47.522317    1312 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0519 22:27:53.227] I0519 22:27:47.536982    1312 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0519 22:27:53.227] I0519 22:27:47.948338    1312 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0519 22:27:53.227] I0519 22:27:47.955649    1312 e2e_node_suite_test.go:191] Tests Finished
I0519 22:27:53.227] 
I0519 22:27:53.228] 
I0519 22:27:53.228] Ran 39 of 303 Specs in 272.210 seconds
I0519 22:27:53.228] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0519 22:27:53.228] 
I0519 22:27:53.228] 
I0519 22:27:53.228] Ginkgo ran 1 suite in 4m35.534709902s
I0519 22:27:53.228] Test Suite Passed
I0519 22:27:53.228] 
I0519 22:27:53.228] Success Finished Test Suite on Host tmp-node-e2e-0f27b276-cos-stable-60-9592-84-0
... skipping 495 lines ...
I0519 22:27:58.558] May 19 22:24:43.470: INFO: Skipping waiting for service account
I0519 22:27:58.558] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.558]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:58.558] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0519 22:27:58.558]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0519 22:27:58.558] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0519 22:27:58.559] STEP: Watching for error events or started pod
I0519 22:27:58.559] STEP: Checking that the pod was rejected
I0519 22:27:58.559] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.559]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:58.559] May 19 22:24:45.534: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0519 22:27:58.559] STEP: Destroying namespace "sysctl-6613" for this suite.
I0519 22:27:58.559] May 19 22:24:51.543: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 318 lines ...
I0519 22:27:58.593] May 19 22:25:23.809: INFO: Skipping waiting for service account
I0519 22:27:58.593] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.594]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:58.594] [It] should support sysctls
I0519 22:27:58.594]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0519 22:27:58.594] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:58.594] STEP: Watching for error events or started pod
I0519 22:27:58.594] STEP: Waiting for pod completion
I0519 22:27:58.594] STEP: Checking that the pod succeeded
I0519 22:27:58.594] STEP: Getting logs from the pod
I0519 22:27:58.594] STEP: Checking that the sysctl is actually updated
I0519 22:27:58.594] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.595]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 469 lines ...
I0519 22:27:58.644] May 19 22:26:07.656: INFO: Skipping waiting for service account
I0519 22:27:58.644] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.644]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:27:58.645] [It] should support unsafe sysctls which are actually whitelisted
I0519 22:27:58.645]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0519 22:27:58.645] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:27:58.645] STEP: Watching for error events or started pod
I0519 22:27:58.645] STEP: Waiting for pod completion
I0519 22:27:58.645] STEP: Checking that the pod succeeded
I0519 22:27:58.645] STEP: Getting logs from the pod
I0519 22:27:58.645] STEP: Checking that the sysctl is actually updated
I0519 22:27:58.645] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:27:58.645]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 64 lines ...
I0519 22:27:58.653] STEP: Wait for 0 temp events generated
I0519 22:27:58.653] STEP: Wait for 0 total events generated
I0519 22:27:58.653] STEP: Make sure only 0 total events generated
I0519 22:27:58.653] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.653] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.653] STEP: should not generate events for too old log
I0519 22:27:58.653] STEP: Inject 3 logs: "temporary error"
I0519 22:27:58.653] STEP: Wait for 0 temp events generated
I0519 22:27:58.653] STEP: Wait for 0 total events generated
I0519 22:27:58.653] STEP: Make sure only 0 total events generated
I0519 22:27:58.653] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.654] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.654] STEP: should not change node condition for too old log
I0519 22:27:58.654] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:58.654] STEP: Wait for 0 temp events generated
I0519 22:27:58.654] STEP: Wait for 0 total events generated
I0519 22:27:58.654] STEP: Make sure only 0 total events generated
I0519 22:27:58.654] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.654] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.654] STEP: should generate event for old log within lookback duration
I0519 22:27:58.654] STEP: Inject 3 logs: "temporary error"
I0519 22:27:58.655] STEP: Wait for 3 temp events generated
I0519 22:27:58.655] STEP: Wait for 3 total events generated
I0519 22:27:58.655] STEP: Make sure only 3 total events generated
I0519 22:27:58.655] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.655] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.655] STEP: should change node condition for old log within lookback duration
I0519 22:27:58.655] STEP: Inject 1 logs: "permanent error 1"
I0519 22:27:58.655] STEP: Wait for 3 temp events generated
I0519 22:27:58.655] STEP: Wait for 4 total events generated
I0519 22:27:58.655] STEP: Make sure only 4 total events generated
I0519 22:27:58.656] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.656] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.656] STEP: should generate event for new log
I0519 22:27:58.656] STEP: Inject 3 logs: "temporary error"
I0519 22:27:58.656] STEP: Wait for 6 temp events generated
I0519 22:27:58.656] STEP: Wait for 7 total events generated
I0519 22:27:58.656] STEP: Make sure only 7 total events generated
I0519 22:27:58.656] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.656] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.656] STEP: should not update node condition with the same reason
I0519 22:27:58.657] STEP: Inject 1 logs: "permanent error 1different message"
I0519 22:27:58.657] STEP: Wait for 6 temp events generated
I0519 22:27:58.657] STEP: Wait for 7 total events generated
I0519 22:27:58.657] STEP: Make sure only 7 total events generated
I0519 22:27:58.657] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.657] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.657] STEP: should change node condition for new log
I0519 22:27:58.657] STEP: Inject 1 logs: "permanent error 2"
I0519 22:27:58.657] STEP: Wait for 6 temp events generated
I0519 22:27:58.657] STEP: Wait for 8 total events generated
I0519 22:27:58.658] STEP: Make sure only 8 total events generated
I0519 22:27:58.658] STEP: Make sure node condition "TestCondition" is set
I0519 22:27:58.658] STEP: Make sure node condition "TestCondition" is stable
I0519 22:27:58.658] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 23 lines ...
I0519 22:27:58.660] ------------------------------
I0519 22:27:58.660] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:58.660]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:58.661] STEP: Creating a kubernetes client
I0519 22:27:58.661] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:58.661] May 19 22:24:43.192: INFO: Skipping waiting for service account
I0519 22:27:58.661] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.661]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:58.661] May 19 22:26:43.300: INFO: Deleting pod "var-expansion-00698115-0ad5-474e-9303-7fd1c6d54436" in namespace "var-expansion-8628"
I0519 22:27:58.661] May 19 22:26:43.318: INFO: Wait up to 5m0s for pod "var-expansion-00698115-0ad5-474e-9303-7fd1c6d54436" to be fully deleted
I0519 22:27:58.661] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:58.661]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:58.662] May 19 22:26:45.322: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:58.662] May 19 22:26:51.380: INFO: namespace var-expansion-8628 deletion completed in 6.056742212s
I0519 22:27:58.662] 
I0519 22:27:58.662] 
I0519 22:27:58.662] • [SLOW TEST:128.191 seconds]
I0519 22:27:58.662] [k8s.io] Variable Expansion
I0519 22:27:58.662] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:58.663]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.663]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:27:58.663] ------------------------------
I0519 22:27:58.663] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:58.663]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:58.663] STEP: Creating a kubernetes client
I0519 22:27:58.663] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:58.663] May 19 22:24:55.731: INFO: Skipping waiting for service account
I0519 22:27:58.664] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.664]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:58.664] May 19 22:26:55.802: INFO: Deleting pod "var-expansion-56ed449a-6c45-46dd-baad-a4593b1352ca" in namespace "var-expansion-6219"
I0519 22:27:58.664] May 19 22:26:55.807: INFO: Wait up to 5m0s for pod "var-expansion-56ed449a-6c45-46dd-baad-a4593b1352ca" to be fully deleted
I0519 22:27:58.664] [AfterEach] [k8s.io] Variable Expansion
I0519 22:27:58.664]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:27:58.664] May 19 22:27:05.813: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:27:58.665] May 19 22:27:11.897: INFO: namespace var-expansion-6219 deletion completed in 6.069348309s
I0519 22:27:58.665] 
I0519 22:27:58.665] 
I0519 22:27:58.665] • [SLOW TEST:136.169 seconds]
I0519 22:27:58.665] [k8s.io] Variable Expansion
I0519 22:27:58.665] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:27:58.665]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.665]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:27:58.665] ------------------------------
I0519 22:27:58.665] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:27:58.666]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:58.666] STEP: Creating a kubernetes client
I0519 22:27:58.666] STEP: Building a namespace api object, basename var-expansion
... skipping 43 lines ...
I0519 22:27:58.671]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:27:58.671] STEP: Creating a kubernetes client
I0519 22:27:58.671] STEP: Building a namespace api object, basename var-expansion
I0519 22:27:58.671] May 19 22:25:02.083: INFO: Skipping waiting for service account
I0519 22:27:58.671] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.671]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0519 22:27:58.671] STEP: creating the pod with failed condition
I0519 22:27:58.672] STEP: updating the pod
I0519 22:27:58.672] May 19 22:27:02.707: INFO: Successfully updated pod "var-expansion-0a1e58a1-1087-4fe4-be8f-6796a134eb10"
I0519 22:27:58.672] STEP: waiting for pod running
I0519 22:27:58.672] STEP: deleting the pod gracefully
I0519 22:27:58.672] May 19 22:27:04.754: INFO: Deleting pod "var-expansion-0a1e58a1-1087-4fe4-be8f-6796a134eb10" in namespace "var-expansion-6620"
I0519 22:27:58.672] May 19 22:27:04.760: INFO: Wait up to 5m0s for pod "var-expansion-0a1e58a1-1087-4fe4-be8f-6796a134eb10" to be fully deleted
... skipping 11 lines ...
I0519 22:27:58.673]   should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:27:58.673]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0519 22:27:58.674] ------------------------------
I0519 22:27:58.674] I0519 22:27:50.840628    1320 e2e_node_suite_test.go:186] Stopping node services...
I0519 22:27:58.674] I0519 22:27:50.840661    1320 server.go:257] Kill server "services"
I0519 22:27:58.674] I0519 22:27:50.840688    1320 server.go:294] Killing process 1831 (services) with -TERM
I0519 22:27:58.674] E0519 22:27:50.927638    1320 services.go:89] Failed to stop services: error stopping "services": waitid: no child processes
I0519 22:27:58.674] I0519 22:27:50.927658    1320 server.go:257] Kill server "kubelet"
I0519 22:27:58.674] I0519 22:27:50.938507    1320 services.go:148] Fetching log files...
I0519 22:27:58.674] I0519 22:27:50.938585    1320 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0519 22:27:58.674] I0519 22:27:50.963978    1320 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0519 22:27:58.675] I0519 22:27:51.587536    1320 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0519 22:27:58.675] I0519 22:27:51.597133    1320 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190519T222259.service].
I0519 22:27:58.675] I0519 22:27:51.877204    1320 e2e_node_suite_test.go:191] Tests Finished
I0519 22:27:58.675] 
I0519 22:27:58.675] 
I0519 22:27:58.675] Ran 39 of 303 Specs in 274.859 seconds
I0519 22:27:58.675] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0519 22:27:58.675] 
I0519 22:27:58.675] 
I0519 22:27:58.675] Ginkgo ran 1 suite in 4m39.372417336s
I0519 22:27:58.675] Test Suite Passed
I0519 22:27:58.675] 
I0519 22:27:58.676] Success Finished Test Suite on Host tmp-node-e2e-0f27b276-cos-stable-63-10032-71-0
... skipping 653 lines ...
I0519 22:28:00.121] May 19 22:24:49.257: INFO: Skipping waiting for service account
I0519 22:28:00.121] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.121]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:28:00.122] [It] should support sysctls
I0519 22:28:00.122]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0519 22:28:00.122] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:28:00.122] STEP: Watching for error events or started pod
I0519 22:28:00.122] STEP: Waiting for pod completion
I0519 22:28:00.122] STEP: Checking that the pod succeeded
I0519 22:28:00.122] STEP: Getting logs from the pod
I0519 22:28:00.122] STEP: Checking that the sysctl is actually updated
I0519 22:28:00.122] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.122]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 147 lines ...
I0519 22:28:00.142] May 19 22:25:03.906: INFO: Skipping waiting for service account
I0519 22:28:00.142] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.143]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:28:00.143] [It] should support unsafe sysctls which are actually whitelisted
I0519 22:28:00.143]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0519 22:28:00.143] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0519 22:28:00.143] STEP: Watching for error events or started pod
I0519 22:28:00.143] STEP: Waiting for pod completion
I0519 22:28:00.143] STEP: Checking that the pod succeeded
I0519 22:28:00.143] STEP: Getting logs from the pod
I0519 22:28:00.143] STEP: Checking that the sysctl is actually updated
I0519 22:28:00.143] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.144]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 355 lines ...
I0519 22:28:00.183] May 19 22:25:56.470: INFO: Skipping waiting for service account
I0519 22:28:00.183] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.183]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0519 22:28:00.183] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0519 22:28:00.183]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0519 22:28:00.183] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0519 22:28:00.183] STEP: Watching for error events or started pod
I0519 22:28:00.183] STEP: Checking that the pod was rejected
I0519 22:28:00.183] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0519 22:28:00.184]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:28:00.184] May 19 22:25:58.531: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0519 22:28:00.184] STEP: Destroying namespace "sysctl-2588" for this suite.
I0519 22:28:00.184] May 19 22:26:04.543: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 193 lines ...
I0519 22:28:00.205] STEP: Wait for 0 temp events generated
I0519 22:28:00.205] STEP: Wait for 0 total events generated
I0519 22:28:00.205] STEP: Make sure only 0 total events generated
I0519 22:28:00.205] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.205] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.206] STEP: should not generate events for too old log
I0519 22:28:00.206] STEP: Inject 3 logs: "temporary error"
I0519 22:28:00.206] STEP: Wait for 0 temp events generated
I0519 22:28:00.206] STEP: Wait for 0 total events generated
I0519 22:28:00.206] STEP: Make sure only 0 total events generated
I0519 22:28:00.206] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.206] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.206] STEP: should not change node condition for too old log
I0519 22:28:00.206] STEP: Inject 1 logs: "permanent error 1"
I0519 22:28:00.206] STEP: Wait for 0 temp events generated
I0519 22:28:00.207] STEP: Wait for 0 total events generated
I0519 22:28:00.207] STEP: Make sure only 0 total events generated
I0519 22:28:00.207] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.207] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.207] STEP: should generate event for old log within lookback duration
I0519 22:28:00.207] STEP: Inject 3 logs: "temporary error"
I0519 22:28:00.207] STEP: Wait for 3 temp events generated
I0519 22:28:00.207] STEP: Wait for 3 total events generated
I0519 22:28:00.207] STEP: Make sure only 3 total events generated
I0519 22:28:00.208] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.208] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.208] STEP: should change node condition for old log within lookback duration
I0519 22:28:00.208] STEP: Inject 1 logs: "permanent error 1"
I0519 22:28:00.208] STEP: Wait for 3 temp events generated
I0519 22:28:00.208] STEP: Wait for 4 total events generated
I0519 22:28:00.208] STEP: Make sure only 4 total events generated
I0519 22:28:00.208] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.208] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.208] STEP: should generate event for new log
I0519 22:28:00.209] STEP: Inject 3 logs: "temporary error"
I0519 22:28:00.209] STEP: Wait for 6 temp events generated
I0519 22:28:00.209] STEP: Wait for 7 total events generated
I0519 22:28:00.209] STEP: Make sure only 7 total events generated
I0519 22:28:00.209] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.209] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.209] STEP: should not update node condition with the same reason
I0519 22:28:00.209] STEP: Inject 1 logs: "permanent error 1different message"
I0519 22:28:00.209] STEP: Wait for 6 temp events generated
I0519 22:28:00.209] STEP: Wait for 7 total events generated
I0519 22:28:00.210] STEP: Make sure only 7 total events generated
I0519 22:28:00.210] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.210] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.210] STEP: should change node condition for new log
I0519 22:28:00.210] STEP: Inject 1 logs: "permanent error 2"
I0519 22:28:00.210] STEP: Wait for 6 temp events generated
I0519 22:28:00.210] STEP: Wait for 8 total events generated
I0519 22:28:00.210] STEP: Make sure only 8 total events generated
I0519 22:28:00.210] STEP: Make sure node condition "TestCondition" is set
I0519 22:28:00.211] STEP: Make sure node condition "TestCondition" is stable
I0519 22:28:00.211] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 23 lines ...
I0519 22:28:00.213] ------------------------------
I0519 22:28:00.213] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:28:00.214]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:28:00.214] STEP: Creating a kubernetes client
I0519 22:28:00.214] STEP: Building a namespace api object, basename var-expansion
I0519 22:28:00.214] May 19 22:24:45.277: INFO: Skipping waiting for service account
I0519 22:28:00.214] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:28:00.214]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:28:00.214] May 19 22:26:45.394: INFO: Deleting pod "var-expansion-b9360edd-8a81-4335-8609-c2469e6b30c4" in namespace "var-expansion-142"
I0519 22:28:00.214] May 19 22:26:45.400: INFO: Wait up to 5m0s for pod "var-expansion-b9360edd-8a81-4335-8609-c2469e6b30c4" to be fully deleted
I0519 22:28:00.214] [AfterEach] [k8s.io] Variable Expansion
I0519 22:28:00.215]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:28:00.215] May 19 22:26:47.410: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:28:00.215] May 19 22:26:53.464: INFO: namespace var-expansion-142 deletion completed in 6.052408512s
I0519 22:28:00.215] 
I0519 22:28:00.215] 
I0519 22:28:00.215] • [SLOW TEST:128.192 seconds]
I0519 22:28:00.215] [k8s.io] Variable Expansion
I0519 22:28:00.215] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:28:00.216]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:28:00.216]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0519 22:28:00.216] ------------------------------
I0519 22:28:00.216] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:28:00.216]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:28:00.216] STEP: Creating a kubernetes client
I0519 22:28:00.216] STEP: Building a namespace api object, basename var-expansion
I0519 22:28:00.216] May 19 22:25:12.427: INFO: Skipping waiting for service account
I0519 22:28:00.216] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:28:00.217]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:28:00.217] May 19 22:27:12.455: INFO: Deleting pod "var-expansion-10b30ab8-88b8-4257-913e-6452e7aa1970" in namespace "var-expansion-8988"
I0519 22:28:00.217] May 19 22:27:12.460: INFO: Wait up to 5m0s for pod "var-expansion-10b30ab8-88b8-4257-913e-6452e7aa1970" to be fully deleted
I0519 22:28:00.217] [AfterEach] [k8s.io] Variable Expansion
I0519 22:28:00.217]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0519 22:28:00.217] May 19 22:27:14.467: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0519 22:28:00.218] May 19 22:27:20.526: INFO: namespace var-expansion-8988 deletion completed in 6.056499285s
I0519 22:28:00.218] 
I0519 22:28:00.218] 
I0519 22:28:00.218] • [SLOW TEST:128.104 seconds]
I0519 22:28:00.218] [k8s.io] Variable Expansion
I0519 22:28:00.218] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0519 22:28:00.218]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:28:00.218]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0519 22:28:00.218] ------------------------------
I0519 22:28:00.218] [BeforeEach] [k8s.io] Variable Expansion
I0519 22:28:00.219]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0519 22:28:00.219] STEP: Creating a kubernetes client
I0519 22:28:00.219] STEP: Building a namespace api object, basename var-expansion
I0519 22:28:00.219] May 19 22:24:57.355: INFO: Skipping waiting for service account
I0519 22:28:00.219] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0519 22:28:00.219]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0519 22:28:00.219] STEP: creating the pod with failed condition
I0519 22:28:00.219] STEP: updating the pod
I0519 22:28:00.220] May 19 22:26:57.910: INFO: Successfully updated pod "var-expansion-89621c2b-2f32-45b9-9edd-8f81e1ec51eb"
I0519 22:28:00.220] STEP: waiting for pod running
I0519 22:28:00.220] STEP: deleting the pod gracefully
I0519 22:28:00.220] May 19 22:26:59.936: INFO: Deleting pod "var-expansion-89621c2b-2f32-45b9-9edd-8f81e1ec51eb" in namespace "var-expansion-2774"
I0519 22:28:00.220] May 19 22:26:59.940: INFO: Wait up to 5m0s for pod "var-expansion-89621c2b-2f32-45b9-9edd-8f81e1ec51eb" to be fully deleted
... skipping 67 lines ...
I0519 22:28:00.228] I0519 22:27:54.672569    2495 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190519T222259.service].
I0519 22:28:00.228] I0519 22:27:54.805954    2495 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0519 22:28:00.228] I0519 22:27:54.815640    2495 e2e_node_suite_test.go:191] Tests Finished
I0519 22:28:00.228] 
I0519 22:28:00.228] 
I0519 22:28:00.228] Ran 39 of 303 Specs in 278.715 seconds
I0519 22:28:00.228] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0519 22:28:00.228] 
I0519 22:28:00.228] 
I0519 22:28:00.229] Ginkgo ran 1 suite in 4m41.084606244s
I0519 22:28:00.229] Test Suite Passed
I0519 22:28:00.229] 
I0519 22:28:00.229] Success Finished Test Suite on Host tmp-node-e2e-0f27b276-ubuntu-gke-1804-d1703-0-v20181113
... skipping 6 lines ...
W0519 22:28:00.516] 2019/05/19 22:28:00 process.go:155: Step 'go run /go/src/k8s.io/kubernetes/test/e2e_node/runner/remote/run_remote.go --cleanup --logtostderr --vmodule=*=4 --ssh-env=gce --results-dir=/workspace/_artifacts --project=k8s-jkns-ci-node-e2e --zone=us-west1-b --ssh-user=prow --ssh-key=/workspace/.ssh/google_compute_engine --ginkgo-flags=--nodes=8 --focus="\[NodeFeature:.+\]" --skip="\[Flaky\]|\[Serial\]" --test_args=--kubelet-flags="--cgroups-per-qos=true --cgroup-root=/" --test-timeout=1h5m0s --image-config-file=/workspace/test-infra/jobs/e2e_node/image-config.yaml' finished in 9m54.085295284s
W0519 22:28:00.516] 2019/05/19 22:28:00 node.go:42: Noop - Node DumpClusterLogs() - /workspace/_artifacts: 
W0519 22:28:00.517] 2019/05/19 22:28:00 node.go:52: Noop - Node Down()
W0519 22:28:00.517] 2019/05/19 22:28:00 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W0519 22:28:00.518] 2019/05/19 22:28:00 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
W0519 22:28:00.837] 2019/05/19 22:28:00 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 321.024449ms
W0519 22:28:00.837] 2019/05/19 22:28:00 main.go:314: Something went wrong: encountered 1 errors: [error during go run /go/src/k8s.io/kubernetes/test/e2e_node/runner/remote/run_remote.go --cleanup --logtostderr --vmodule=*=4 --ssh-env=gce --results-dir=/workspace/_artifacts --project=k8s-jkns-ci-node-e2e --zone=us-west1-b --ssh-user=prow --ssh-key=/workspace/.ssh/google_compute_engine --ginkgo-flags=--nodes=8 --focus="\[NodeFeature:.+\]" --skip="\[Flaky\]|\[Serial\]" --test_args=--kubelet-flags="--cgroups-per-qos=true --cgroup-root=/" --test-timeout=1h5m0s --image-config-file=/workspace/test-infra/jobs/e2e_node/image-config.yaml: exit status 1]
W0519 22:28:00.841] Traceback (most recent call last):
W0519 22:28:00.842]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W0519 22:28:00.842]     main(parse_args())
W0519 22:28:00.842]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W0519 22:28:00.842]     mode.start(runner_args)
W0519 22:28:00.842]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W0519 22:28:00.842]     check_env(env, self.command, *args)
W0519 22:28:00.843]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W0519 22:28:00.843]     subprocess.check_call(cmd, env=env)
W0519 22:28:00.843]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W0519 22:28:00.843]     raise CalledProcessError(retcode, cmd)
W0519 22:28:00.844] subprocess.CalledProcessError: Command '('kubetest', '--dump=/workspace/_artifacts', '--gcp-service-account=/etc/service-account/service-account.json', '--up', '--down', '--test', '--deployment=node', '--provider=gce', '--cluster=bootstrap-e2e', '--gcp-network=bootstrap-e2e', '--gcp-project=k8s-jkns-ci-node-e2e', '--gcp-zone=us-west1-b', '--node-args=--image-config-file=/workspace/test-infra/jobs/e2e_node/image-config.yaml', '--node-test-args=--kubelet-flags="--cgroups-per-qos=true --cgroup-root=/"', '--node-tests=true', '--test_args=--nodes=8 --focus="\\[NodeFeature:.+\\]" --skip="\\[Flaky\\]|\\[Serial\\]"', '--timeout=65m')' returned non-zero exit status 1
E0519 22:28:00.853] Command failed
I0519 22:28:00.853] process 309 exited with code 1 after 9.9m
E0519 22:28:00.854] FAIL: ci-kubernetes-node-kubelet-features-beta
I0519 22:28:00.854] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0519 22:28:01.492] Activated service account credentials for: [pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com]
I0519 22:28:01.554] process 38535 exited with code 0 after 0.0m
I0519 22:28:01.554] Call:  gcloud config get-value account
I0519 22:28:01.920] process 38547 exited with code 0 after 0.0m
I0519 22:28:01.920] Will upload results to gs://kubernetes-jenkins/logs using pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com
I0519 22:28:01.920] Upload result and artifacts...
I0519 22:28:01.920] Gubernator results at https://gubernator.k8s.io/build/kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130235895358689280
I0519 22:28:01.921] Call:  gsutil ls gs://kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130235895358689280/artifacts
W0519 22:28:03.097] CommandException: One or more URLs matched no objects.
E0519 22:28:03.267] Command failed
I0519 22:28:03.268] process 38559 exited with code 1 after 0.0m
W0519 22:28:03.268] Remote dir gs://kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130235895358689280/artifacts not exist yet
I0519 22:28:03.268] Call:  gsutil -m -q -o GSUtil:use_magicfile=True cp -r -c -z log,txt,xml /workspace/_artifacts gs://kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130235895358689280/artifacts
I0519 22:28:06.522] process 38701 exited with code 0 after 0.1m
I0519 22:28:06.523] Call:  git rev-parse HEAD
I0519 22:28:06.528] process 39357 exited with code 0 after 0.0m
... skipping 13 lines ...