This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 1 failed / 124 succeeded
Started2019-05-21 08:50
Elapsed11m46s
Revision
Buildergke-prow-containerd-pool-99179761-c7v4
links{u'resultstore': {u'url': u'https://source.cloud.google.com/results/invocations/e5cb4817-bdaf-4115-b369-97598346ffc8/targets/test'}}
pod6a53d84f-7ba5-11e9-9181-56a74f322e94
resultstorehttps://source.cloud.google.com/results/invocations/e5cb4817-bdaf-4115-b369-97598346ffc8/targets/test
infra-commit3ee21a13d
job-versionv1.15.0-beta.0.289+5b4de8c6ac4a34
pod6a53d84f-7ba5-11e9-9181-56a74f322e94
repok8s.io/kubernetes
repo-commit5b4de8c6ac4a34323a8582765a969d5ecfcf5467
repos{u'k8s.io/kubernetes': u'release-1.15'}
revisionv1.15.0-beta.0.289+5b4de8c6ac4a34

Test Failures


Node Tests 10m31s

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 124 Passed Tests

Show 792 Skipped Tests

Error lines from build-log.txt

... skipping 289 lines ...
W0521 08:56:51.748] I0521 08:56:51.747920    4324 utils.go:117] Killing any existing node processes on "tmp-node-e2e-bd1040f3-ubuntu-gke-1804-d1703-0-v20181113"
W0521 08:56:51.854] I0521 08:56:51.853895    4324 node_e2e.go:91] GCI/COS node and GCI/COS mounter both detected, modifying --experimental-mounter-path accordingly
W0521 08:56:51.854] I0521 08:56:51.853939    4324 node_e2e.go:147] Starting tests on "tmp-node-e2e-bd1040f3-cos-stable-60-9592-84-0"
W0521 08:56:51.889] I0521 08:56:51.888655    4324 node_e2e.go:91] GCI/COS node and GCI/COS mounter both detected, modifying --experimental-mounter-path accordingly
W0521 08:56:51.889] I0521 08:56:51.888702    4324 node_e2e.go:147] Starting tests on "tmp-node-e2e-bd1040f3-cos-stable-63-10032-71-0"
W0521 08:56:53.205] I0521 08:56:53.204678    4324 node_e2e.go:147] Starting tests on "tmp-node-e2e-bd1040f3-ubuntu-gke-1804-d1703-0-v20181113"
W0521 08:58:58.371] I0521 08:58:58.371202    4324 remote.go:197] Test failed unexpectedly. Attempting to retrieving system logs (only works for nodes with journald)
W0521 08:58:59.006] I0521 08:58:59.006313    4324 remote.go:202] Got the system logs from journald; copying it back...
W0521 08:58:59.847] I0521 08:58:59.847266    4324 remote.go:122] Copying test artifacts from "tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911"
W0521 08:59:01.041] I0521 08:59:01.041346    4324 run_remote.go:718] Deleting instance "tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911"
I0521 08:59:01.471] 
I0521 08:59:01.471] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
I0521 08:59:01.472] >                              START TEST                                >
I0521 08:59:01.472] >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
I0521 08:59:01.472] Start Test Suite on Host tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911
I0521 08:59:01.472] 
I0521 08:59:01.472] Failure Finished Test Suite on Host tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911
I0521 08:59:01.473] [failed to install cni plugin on "tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911": 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.227.168.114 -- sudo sh -c 'mkdir -p /tmp/node-e2e-20190521T085639/cni/bin ; curl -s -L https://dl.k8s.io/network-plugins/cni-plugins-amd64-v0.7.5.tgz | tar -xz -C /tmp/node-e2e-20190521T085639/cni/bin'] failed with error: exit status 2 output: "\ngzip: stdin: unexpected end of file\ntar: Child returned status 1\ntar: Error is not recoverable: exiting now\n", command [scp -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 -r prow@35.227.168.114:/tmp/node-e2e-20190521T085639/results/*.log /workspace/_artifacts/tmp-node-e2e-bd1040f3-coreos-beta-1883-1-0-v20180911] failed with error: exit status 1]
I0521 08:59:01.473] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
I0521 08:59:01.473] <                              FINISH TEST                               <
I0521 08:59:01.473] <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
I0521 08:59:01.473] 
W0521 09:01:59.879] I0521 09:01:59.878242    4324 remote.go:122] Copying test artifacts from "tmp-node-e2e-bd1040f3-cos-stable-60-9592-84-0"
W0521 09:02:03.805] I0521 09:02:03.804313    4324 remote.go:122] Copying test artifacts from "tmp-node-e2e-bd1040f3-cos-stable-63-10032-71-0"
... skipping 276 lines ...
I0521 09:02:05.224] May 21 08:58:02.889: INFO: Skipping waiting for service account
I0521 09:02:05.224] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.224]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:05.224] [It] should support unsafe sysctls which are actually whitelisted
I0521 09:02:05.224]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0521 09:02:05.224] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:05.224] STEP: Watching for error events or started pod
I0521 09:02:05.224] STEP: Waiting for pod completion
I0521 09:02:05.224] STEP: Checking that the pod succeeded
I0521 09:02:05.224] STEP: Getting logs from the pod
I0521 09:02:05.225] STEP: Checking that the sysctl is actually updated
I0521 09:02:05.225] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.225]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 488 lines ...
I0521 09:02:05.303] May 21 08:58:34.355: INFO: Skipping waiting for service account
I0521 09:02:05.304] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.304]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:05.304] [It] should support sysctls
I0521 09:02:05.304]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0521 09:02:05.304] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:05.304] STEP: Watching for error events or started pod
I0521 09:02:05.305] STEP: Waiting for pod completion
I0521 09:02:05.305] STEP: Checking that the pod succeeded
I0521 09:02:05.305] STEP: Getting logs from the pod
I0521 09:02:05.305] STEP: Checking that the sysctl is actually updated
I0521 09:02:05.305] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.305]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 220 lines ...
I0521 09:02:05.334] May 21 08:58:57.200: INFO: Skipping waiting for service account
I0521 09:02:05.334] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.334]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:05.334] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0521 09:02:05.335]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0521 09:02:05.335] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0521 09:02:05.335] STEP: Watching for error events or started pod
I0521 09:02:05.335] STEP: Checking that the pod was rejected
I0521 09:02:05.335] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:05.335]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:05.335] May 21 08:58:59.252: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0521 09:02:05.335] STEP: Destroying namespace "sysctl-7332" for this suite.
I0521 09:02:05.335] May 21 08:59:05.276: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 322 lines ...
I0521 09:02:05.369] STEP: Wait for 0 temp events generated
I0521 09:02:05.370] STEP: Wait for 0 total events generated
I0521 09:02:05.370] STEP: Make sure only 0 total events generated
I0521 09:02:05.370] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.370] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.370] STEP: should not generate events for too old log
I0521 09:02:05.370] STEP: Inject 3 logs: "temporary error"
I0521 09:02:05.370] STEP: Wait for 0 temp events generated
I0521 09:02:05.370] STEP: Wait for 0 total events generated
I0521 09:02:05.370] STEP: Make sure only 0 total events generated
I0521 09:02:05.370] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.370] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.371] STEP: should not change node condition for too old log
I0521 09:02:05.371] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:05.371] STEP: Wait for 0 temp events generated
I0521 09:02:05.371] STEP: Wait for 0 total events generated
I0521 09:02:05.371] STEP: Make sure only 0 total events generated
I0521 09:02:05.371] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.371] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.371] STEP: should generate event for old log within lookback duration
I0521 09:02:05.371] STEP: Inject 3 logs: "temporary error"
I0521 09:02:05.371] STEP: Wait for 3 temp events generated
I0521 09:02:05.371] STEP: Wait for 3 total events generated
I0521 09:02:05.372] STEP: Make sure only 3 total events generated
I0521 09:02:05.372] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.372] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.372] STEP: should change node condition for old log within lookback duration
I0521 09:02:05.372] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:05.372] STEP: Wait for 3 temp events generated
I0521 09:02:05.372] STEP: Wait for 4 total events generated
I0521 09:02:05.372] STEP: Make sure only 4 total events generated
I0521 09:02:05.372] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.373] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.373] STEP: should generate event for new log
I0521 09:02:05.373] STEP: Inject 3 logs: "temporary error"
I0521 09:02:05.373] STEP: Wait for 6 temp events generated
I0521 09:02:05.373] STEP: Wait for 7 total events generated
I0521 09:02:05.373] STEP: Make sure only 7 total events generated
I0521 09:02:05.373] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.373] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.373] STEP: should not update node condition with the same reason
I0521 09:02:05.373] STEP: Inject 1 logs: "permanent error 1different message"
I0521 09:02:05.373] STEP: Wait for 6 temp events generated
I0521 09:02:05.374] STEP: Wait for 7 total events generated
I0521 09:02:05.374] STEP: Make sure only 7 total events generated
I0521 09:02:05.374] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.374] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.374] STEP: should change node condition for new log
I0521 09:02:05.374] STEP: Inject 1 logs: "permanent error 2"
I0521 09:02:05.374] STEP: Wait for 6 temp events generated
I0521 09:02:05.374] STEP: Wait for 8 total events generated
I0521 09:02:05.374] STEP: Make sure only 8 total events generated
I0521 09:02:05.374] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:05.374] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:05.375] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 50 lines ...
I0521 09:02:05.380] ------------------------------
I0521 09:02:05.380] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:05.380]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:05.380] STEP: Creating a kubernetes client
I0521 09:02:05.380] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:05.380] May 21 08:58:17.533: INFO: Skipping waiting for service account
I0521 09:02:05.380] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.381]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:05.381] May 21 09:00:17.601: INFO: Deleting pod "var-expansion-d5b78f3c-e9b0-4d49-ac8d-574ee6dec635" in namespace "var-expansion-1386"
I0521 09:02:05.381] May 21 09:00:17.605: INFO: Wait up to 5m0s for pod "var-expansion-d5b78f3c-e9b0-4d49-ac8d-574ee6dec635" to be fully deleted
I0521 09:02:05.381] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:05.381]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:05.381] May 21 09:00:27.611: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:05.382] May 21 09:00:33.658: INFO: namespace var-expansion-1386 deletion completed in 6.044919673s
I0521 09:02:05.382] 
I0521 09:02:05.382] 
I0521 09:02:05.382] • [SLOW TEST:136.127 seconds]
I0521 09:02:05.382] [k8s.io] Variable Expansion
I0521 09:02:05.382] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:05.382]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.382]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:05.382] ------------------------------
I0521 09:02:05.382] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:05.382]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:05.383] STEP: Creating a kubernetes client
I0521 09:02:05.383] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:05.383] May 21 08:58:35.742: INFO: Skipping waiting for service account
I0521 09:02:05.383] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.383]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:05.383] May 21 09:00:35.753: INFO: Deleting pod "var-expansion-49575f04-6199-46dc-a21b-40d58e7aab50" in namespace "var-expansion-1614"
I0521 09:02:05.383] May 21 09:00:35.757: INFO: Wait up to 5m0s for pod "var-expansion-49575f04-6199-46dc-a21b-40d58e7aab50" to be fully deleted
I0521 09:02:05.383] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:05.383]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:05.384] May 21 09:00:37.763: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:05.384] May 21 09:00:43.811: INFO: namespace var-expansion-1614 deletion completed in 6.046309309s
I0521 09:02:05.384] 
I0521 09:02:05.384] 
I0521 09:02:05.384] • [SLOW TEST:128.072 seconds]
I0521 09:02:05.384] [k8s.io] Variable Expansion
I0521 09:02:05.384] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:05.385]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.385]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:05.385] ------------------------------
I0521 09:02:05.385] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:05.385]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:05.385] STEP: Creating a kubernetes client
I0521 09:02:05.385] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:05.385] May 21 08:59:07.247: INFO: Skipping waiting for service account
I0521 09:02:05.385] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.385]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0521 09:02:05.386] STEP: creating the pod with failed condition
I0521 09:02:05.386] STEP: updating the pod
I0521 09:02:05.386] May 21 09:01:07.796: INFO: Successfully updated pod "var-expansion-ed51d5a0-83bb-4808-8641-b978078294fb"
I0521 09:02:05.386] STEP: waiting for pod running
I0521 09:02:05.386] STEP: deleting the pod gracefully
I0521 09:02:05.386] May 21 09:01:09.840: INFO: Deleting pod "var-expansion-ed51d5a0-83bb-4808-8641-b978078294fb" in namespace "var-expansion-3922"
I0521 09:02:05.386] May 21 09:01:09.845: INFO: Wait up to 5m0s for pod "var-expansion-ed51d5a0-83bb-4808-8641-b978078294fb" to be fully deleted
... skipping 57 lines ...
I0521 09:02:05.393]   should not change the subpath mount on a container restart if the environment variable changes [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:05.393]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:519
I0521 09:02:05.393] ------------------------------
I0521 09:02:05.393] I0521 09:01:59.047839    1324 e2e_node_suite_test.go:186] Stopping node services...
I0521 09:02:05.393] I0521 09:01:59.047881    1324 server.go:257] Kill server "services"
I0521 09:02:05.393] I0521 09:01:59.047892    1324 server.go:294] Killing process 1855 (services) with -TERM
I0521 09:02:05.393] E0521 09:01:59.150654    1324 services.go:89] Failed to stop services: error stopping "services": waitid: no child processes
I0521 09:02:05.394] I0521 09:01:59.150673    1324 server.go:257] Kill server "kubelet"
I0521 09:02:05.394] I0521 09:01:59.161156    1324 services.go:148] Fetching log files...
I0521 09:02:05.394] I0521 09:01:59.161215    1324 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0521 09:02:05.394] I0521 09:01:59.180838    1324 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0521 09:02:05.394] I0521 09:01:59.620625    1324 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0521 09:02:05.394] I0521 09:01:59.628582    1324 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190521T085639.service].
I0521 09:02:05.394] I0521 09:01:59.839412    1324 e2e_node_suite_test.go:191] Tests Finished
I0521 09:02:05.394] 
I0521 09:02:05.394] 
I0521 09:02:05.394] Ran 39 of 303 Specs in 304.091 seconds
I0521 09:02:05.395] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0521 09:02:05.395] 
I0521 09:02:05.395] 
I0521 09:02:05.395] Ginkgo ran 1 suite in 5m7.363040892s
I0521 09:02:05.395] Test Suite Passed
I0521 09:02:05.395] 
I0521 09:02:05.395] Success Finished Test Suite on Host tmp-node-e2e-bd1040f3-cos-stable-60-9592-84-0
... skipping 229 lines ...
I0521 09:02:09.847] May 21 08:58:08.330: INFO: Skipping waiting for service account
I0521 09:02:09.847] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.847]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:09.847] [It] should support unsafe sysctls which are actually whitelisted
I0521 09:02:09.847]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0521 09:02:09.847] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:09.847] STEP: Watching for error events or started pod
I0521 09:02:09.848] STEP: Waiting for pod completion
I0521 09:02:09.848] STEP: Checking that the pod succeeded
I0521 09:02:09.848] STEP: Getting logs from the pod
I0521 09:02:09.848] STEP: Checking that the sysctl is actually updated
I0521 09:02:09.848] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.848]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 476 lines ...
I0521 09:02:09.927] May 21 08:58:37.934: INFO: Skipping waiting for service account
I0521 09:02:09.927] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.928]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:09.928] [It] should support sysctls
I0521 09:02:09.928]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0521 09:02:09.928] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:09.928] STEP: Watching for error events or started pod
I0521 09:02:09.928] STEP: Waiting for pod completion
I0521 09:02:09.928] STEP: Checking that the pod succeeded
I0521 09:02:09.929] STEP: Getting logs from the pod
I0521 09:02:09.929] STEP: Checking that the sysctl is actually updated
I0521 09:02:09.929] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.929]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 285 lines ...
I0521 09:02:09.977] May 21 08:59:02.339: INFO: Skipping waiting for service account
I0521 09:02:09.978] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.978]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:09.978] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0521 09:02:09.978]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0521 09:02:09.978] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0521 09:02:09.978] STEP: Watching for error events or started pod
I0521 09:02:09.979] STEP: Checking that the pod was rejected
I0521 09:02:09.979] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:09.979]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:09.979] May 21 08:59:04.399: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0521 09:02:09.979] STEP: Destroying namespace "sysctl-8074" for this suite.
I0521 09:02:09.979] May 21 08:59:10.405: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 322 lines ...
I0521 09:02:10.028] STEP: Wait for 0 temp events generated
I0521 09:02:10.028] STEP: Wait for 0 total events generated
I0521 09:02:10.028] STEP: Make sure only 0 total events generated
I0521 09:02:10.028] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.028] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.029] STEP: should not generate events for too old log
I0521 09:02:10.029] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.029] STEP: Wait for 0 temp events generated
I0521 09:02:10.029] STEP: Wait for 0 total events generated
I0521 09:02:10.029] STEP: Make sure only 0 total events generated
I0521 09:02:10.029] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.029] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.030] STEP: should not change node condition for too old log
I0521 09:02:10.030] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:10.030] STEP: Wait for 0 temp events generated
I0521 09:02:10.030] STEP: Wait for 0 total events generated
I0521 09:02:10.030] STEP: Make sure only 0 total events generated
I0521 09:02:10.030] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.030] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.031] STEP: should generate event for old log within lookback duration
I0521 09:02:10.031] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.031] STEP: Wait for 3 temp events generated
I0521 09:02:10.031] STEP: Wait for 3 total events generated
I0521 09:02:10.031] STEP: Make sure only 3 total events generated
I0521 09:02:10.031] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.031] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.032] STEP: should change node condition for old log within lookback duration
I0521 09:02:10.032] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:10.032] STEP: Wait for 3 temp events generated
I0521 09:02:10.032] STEP: Wait for 4 total events generated
I0521 09:02:10.032] STEP: Make sure only 4 total events generated
I0521 09:02:10.032] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.032] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.032] STEP: should generate event for new log
I0521 09:02:10.033] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.033] STEP: Wait for 6 temp events generated
I0521 09:02:10.033] STEP: Wait for 7 total events generated
I0521 09:02:10.033] STEP: Make sure only 7 total events generated
I0521 09:02:10.033] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.033] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.033] STEP: should not update node condition with the same reason
I0521 09:02:10.034] STEP: Inject 1 logs: "permanent error 1different message"
I0521 09:02:10.034] STEP: Wait for 6 temp events generated
I0521 09:02:10.034] STEP: Wait for 7 total events generated
I0521 09:02:10.034] STEP: Make sure only 7 total events generated
I0521 09:02:10.034] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.034] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.034] STEP: should change node condition for new log
I0521 09:02:10.035] STEP: Inject 1 logs: "permanent error 2"
I0521 09:02:10.035] STEP: Wait for 6 temp events generated
I0521 09:02:10.035] STEP: Wait for 8 total events generated
I0521 09:02:10.035] STEP: Make sure only 8 total events generated
I0521 09:02:10.035] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.035] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.035] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 50 lines ...
I0521 09:02:10.043] ------------------------------
I0521 09:02:10.043] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.043]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.043] STEP: Creating a kubernetes client
I0521 09:02:10.043] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.044] May 21 08:58:24.195: INFO: Skipping waiting for service account
I0521 09:02:10.044] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.044]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:10.044] May 21 09:00:24.350: INFO: Deleting pod "var-expansion-78e4f6fc-58d1-47d1-ab36-c7e00e6d2a1a" in namespace "var-expansion-1242"
I0521 09:02:10.044] May 21 09:00:24.354: INFO: Wait up to 5m0s for pod "var-expansion-78e4f6fc-58d1-47d1-ab36-c7e00e6d2a1a" to be fully deleted
I0521 09:02:10.044] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:10.045]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:10.045] May 21 09:00:26.359: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:10.045] May 21 09:00:32.419: INFO: namespace var-expansion-1242 deletion completed in 6.057380338s
I0521 09:02:10.045] 
I0521 09:02:10.045] 
I0521 09:02:10.046] • [SLOW TEST:128.248 seconds]
I0521 09:02:10.046] [k8s.io] Variable Expansion
I0521 09:02:10.046] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:10.046]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.046]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:10.046] ------------------------------
I0521 09:02:10.047] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.047]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.047] STEP: Creating a kubernetes client
I0521 09:02:10.047] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.047] May 21 08:58:41.373: INFO: Skipping waiting for service account
I0521 09:02:10.047] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.048]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:10.048] May 21 09:00:41.436: INFO: Deleting pod "var-expansion-2d9cf955-9596-426d-b4fb-ebd3998a3126" in namespace "var-expansion-9648"
I0521 09:02:10.048] May 21 09:00:41.441: INFO: Wait up to 5m0s for pod "var-expansion-2d9cf955-9596-426d-b4fb-ebd3998a3126" to be fully deleted
I0521 09:02:10.048] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:10.048]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:10.048] May 21 09:00:45.447: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:10.049] May 21 09:00:51.506: INFO: namespace var-expansion-9648 deletion completed in 6.057165861s
I0521 09:02:10.049] 
I0521 09:02:10.049] 
I0521 09:02:10.049] • [SLOW TEST:130.135 seconds]
I0521 09:02:10.049] [k8s.io] Variable Expansion
I0521 09:02:10.049] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:10.050]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.050]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:10.050] ------------------------------
I0521 09:02:10.050] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.050]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.050] STEP: Creating a kubernetes client
I0521 09:02:10.051] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.051] May 21 08:59:12.895: INFO: Skipping waiting for service account
I0521 09:02:10.051] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.051]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0521 09:02:10.051] STEP: creating the pod with failed condition
I0521 09:02:10.051] STEP: updating the pod
I0521 09:02:10.051] May 21 09:01:13.514: INFO: Successfully updated pod "var-expansion-0a0a2767-0407-4349-b7bd-cb914d46a74e"
I0521 09:02:10.052] STEP: waiting for pod running
I0521 09:02:10.052] STEP: deleting the pod gracefully
I0521 09:02:10.052] May 21 09:01:15.558: INFO: Deleting pod "var-expansion-0a0a2767-0407-4349-b7bd-cb914d46a74e" in namespace "var-expansion-3058"
I0521 09:02:10.052] May 21 09:01:15.562: INFO: Wait up to 5m0s for pod "var-expansion-0a0a2767-0407-4349-b7bd-cb914d46a74e" to be fully deleted
... skipping 57 lines ...
I0521 09:02:10.062]   should not change the subpath mount on a container restart if the environment variable changes [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.062]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:519
I0521 09:02:10.062] ------------------------------
I0521 09:02:10.062] I0521 09:02:02.684535    1323 e2e_node_suite_test.go:186] Stopping node services...
I0521 09:02:10.063] I0521 09:02:02.684563    1323 server.go:257] Kill server "services"
I0521 09:02:10.063] I0521 09:02:02.684575    1323 server.go:294] Killing process 1826 (services) with -TERM
I0521 09:02:10.063] E0521 09:02:02.793389    1323 services.go:89] Failed to stop services: error stopping "services": waitid: no child processes
I0521 09:02:10.063] I0521 09:02:02.793408    1323 server.go:257] Kill server "kubelet"
I0521 09:02:10.063] I0521 09:02:02.803582    1323 services.go:148] Fetching log files...
I0521 09:02:10.063] I0521 09:02:02.803643    1323 services.go:157] Get log file "kubelet.log" with journalctl command [-u kubelet-20190521T085639.service].
I0521 09:02:10.063] I0521 09:02:03.085807    1323 services.go:157] Get log file "kern.log" with journalctl command [-k].
I0521 09:02:10.064] I0521 09:02:03.107349    1323 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0521 09:02:10.064] I0521 09:02:03.757453    1323 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0521 09:02:10.064] I0521 09:02:03.767766    1323 e2e_node_suite_test.go:191] Tests Finished
I0521 09:02:10.064] 
I0521 09:02:10.064] 
I0521 09:02:10.064] Ran 39 of 303 Specs in 307.457 seconds
I0521 09:02:10.065] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0521 09:02:10.065] 
I0521 09:02:10.065] 
I0521 09:02:10.065] Ginkgo ran 1 suite in 5m11.247714379s
I0521 09:02:10.065] Test Suite Passed
I0521 09:02:10.065] 
I0521 09:02:10.065] Success Finished Test Suite on Host tmp-node-e2e-bd1040f3-cos-stable-63-10032-71-0
... skipping 917 lines ...
I0521 09:02:10.264] May 21 08:59:00.643: INFO: Skipping waiting for service account
I0521 09:02:10.265] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.265]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:10.265] [It] should not launch unsafe, but not explicitly enabled sysctls on the node
I0521 09:02:10.265]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:181
I0521 09:02:10.265] STEP: Creating a pod with a greylisted, but not whitelisted sysctl on the node
I0521 09:02:10.265] STEP: Watching for error events or started pod
I0521 09:02:10.265] STEP: Checking that the pod was rejected
I0521 09:02:10.265] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.265]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:10.265] May 21 08:59:02.704: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
I0521 09:02:10.266] STEP: Destroying namespace "sysctl-7993" for this suite.
I0521 09:02:10.266] May 21 08:59:08.712: INFO: Waiting up to 30s for server preferred namespaced resources to be successfully discovered
... skipping 349 lines ...
I0521 09:02:10.303] May 21 08:59:31.492: INFO: Skipping waiting for service account
I0521 09:02:10.303] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.303]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:10.303] [It] should support unsafe sysctls which are actually whitelisted
I0521 09:02:10.303]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:103
I0521 09:02:10.303] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:10.303] STEP: Watching for error events or started pod
I0521 09:02:10.304] STEP: Waiting for pod completion
I0521 09:02:10.304] STEP: Checking that the pod succeeded
I0521 09:02:10.304] STEP: Getting logs from the pod
I0521 09:02:10.304] STEP: Checking that the sysctl is actually updated
I0521 09:02:10.304] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.304]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 45 lines ...
I0521 09:02:10.309] May 21 08:59:33.260: INFO: Skipping waiting for service account
I0521 09:02:10.309] [BeforeEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.309]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:56
I0521 09:02:10.309] [It] should support sysctls
I0521 09:02:10.309]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/sysctl.go:60
I0521 09:02:10.309] STEP: Creating a pod with the kernel.shm_rmid_forced sysctl
I0521 09:02:10.309] STEP: Watching for error events or started pod
I0521 09:02:10.309] STEP: Waiting for pod completion
I0521 09:02:10.309] STEP: Checking that the pod succeeded
I0521 09:02:10.309] STEP: Getting logs from the pod
I0521 09:02:10.309] STEP: Checking that the sysctl is actually updated
I0521 09:02:10.310] [AfterEach] [k8s.io] Sysctls [NodeFeature:Sysctls]
I0521 09:02:10.310]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
... skipping 30 lines ...
I0521 09:02:10.313] STEP: Wait for 0 temp events generated
I0521 09:02:10.313] STEP: Wait for 0 total events generated
I0521 09:02:10.313] STEP: Make sure only 0 total events generated
I0521 09:02:10.313] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.313] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.314] STEP: should not generate events for too old log
I0521 09:02:10.314] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.314] STEP: Wait for 0 temp events generated
I0521 09:02:10.314] STEP: Wait for 0 total events generated
I0521 09:02:10.314] STEP: Make sure only 0 total events generated
I0521 09:02:10.314] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.314] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.314] STEP: should not change node condition for too old log
I0521 09:02:10.314] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:10.314] STEP: Wait for 0 temp events generated
I0521 09:02:10.315] STEP: Wait for 0 total events generated
I0521 09:02:10.315] STEP: Make sure only 0 total events generated
I0521 09:02:10.315] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.315] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.315] STEP: should generate event for old log within lookback duration
I0521 09:02:10.315] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.315] STEP: Wait for 3 temp events generated
I0521 09:02:10.315] STEP: Wait for 3 total events generated
I0521 09:02:10.315] STEP: Make sure only 3 total events generated
I0521 09:02:10.315] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.315] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.316] STEP: should change node condition for old log within lookback duration
I0521 09:02:10.316] STEP: Inject 1 logs: "permanent error 1"
I0521 09:02:10.316] STEP: Wait for 3 temp events generated
I0521 09:02:10.316] STEP: Wait for 4 total events generated
I0521 09:02:10.316] STEP: Make sure only 4 total events generated
I0521 09:02:10.316] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.316] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.316] STEP: should generate event for new log
I0521 09:02:10.316] STEP: Inject 3 logs: "temporary error"
I0521 09:02:10.316] STEP: Wait for 6 temp events generated
I0521 09:02:10.316] STEP: Wait for 7 total events generated
I0521 09:02:10.317] STEP: Make sure only 7 total events generated
I0521 09:02:10.317] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.317] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.317] STEP: should not update node condition with the same reason
I0521 09:02:10.317] STEP: Inject 1 logs: "permanent error 1different message"
I0521 09:02:10.317] STEP: Wait for 6 temp events generated
I0521 09:02:10.317] STEP: Wait for 7 total events generated
I0521 09:02:10.317] STEP: Make sure only 7 total events generated
I0521 09:02:10.317] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.317] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.318] STEP: should change node condition for new log
I0521 09:02:10.318] STEP: Inject 1 logs: "permanent error 2"
I0521 09:02:10.318] STEP: Wait for 6 temp events generated
I0521 09:02:10.318] STEP: Wait for 8 total events generated
I0521 09:02:10.318] STEP: Make sure only 8 total events generated
I0521 09:02:10.318] STEP: Make sure node condition "TestCondition" is set
I0521 09:02:10.318] STEP: Make sure node condition "TestCondition" is stable
I0521 09:02:10.318] [AfterEach] [k8s.io] SystemLogMonitor
... skipping 26 lines ...
I0521 09:02:10.321] STEP: Creating a kubernetes client
I0521 09:02:10.322] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.322] May 21 08:58:14.595: INFO: No PodSecurityPolicies found; assuming PodSecurityPolicy is disabled.
I0521 09:02:10.322] May 21 08:58:14.595: INFO: Skipping waiting for service account
I0521 09:02:10.322] [It] should verify that a failing subpath expansion can be modified during the lifecycle of a container [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.322]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:319
I0521 09:02:10.322] STEP: creating the pod with failed condition
I0521 09:02:10.322] STEP: updating the pod
I0521 09:02:10.322] May 21 09:00:15.391: INFO: Successfully updated pod "var-expansion-85048dd2-764a-4b56-b8c3-d2228687eabe"
I0521 09:02:10.322] STEP: waiting for pod running
I0521 09:02:10.323] STEP: deleting the pod gracefully
I0521 09:02:10.323] May 21 09:00:17.401: INFO: Deleting pod "var-expansion-85048dd2-764a-4b56-b8c3-d2228687eabe" in namespace "var-expansion-7431"
I0521 09:02:10.323] May 21 09:00:17.407: INFO: Wait up to 5m0s for pod "var-expansion-85048dd2-764a-4b56-b8c3-d2228687eabe" to be fully deleted
... skipping 13 lines ...
I0521 09:02:10.324] ------------------------------
I0521 09:02:10.324] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.325]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.325] STEP: Creating a kubernetes client
I0521 09:02:10.325] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.325] May 21 08:59:03.605: INFO: Skipping waiting for service account
I0521 09:02:10.325] [It] should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.325]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:10.325] May 21 09:01:03.629: INFO: Deleting pod "var-expansion-fefa6a5d-819b-4378-b777-0780be0eb1a3" in namespace "var-expansion-7746"
I0521 09:02:10.325] May 21 09:01:03.634: INFO: Wait up to 5m0s for pod "var-expansion-fefa6a5d-819b-4378-b777-0780be0eb1a3" to be fully deleted
I0521 09:02:10.325] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:10.326]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:10.326] May 21 09:01:07.645: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:10.326] May 21 09:01:13.703: INFO: namespace var-expansion-7746 deletion completed in 6.056350625s
I0521 09:02:10.326] 
I0521 09:02:10.326] 
I0521 09:02:10.326] • [SLOW TEST:130.103 seconds]
I0521 09:02:10.326] [k8s.io] Variable Expansion
I0521 09:02:10.326] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:10.327]   should fail substituting values in a volume subpath with absolute path [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.327]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:271
I0521 09:02:10.327] ------------------------------
I0521 09:02:10.327] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.327]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.327] STEP: Creating a kubernetes client
I0521 09:02:10.327] STEP: Building a namespace api object, basename var-expansion
I0521 09:02:10.327] May 21 08:59:00.781: INFO: Skipping waiting for service account
I0521 09:02:10.327] [It] should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.328]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:10.328] May 21 09:01:00.811: INFO: Deleting pod "var-expansion-c479a9b2-f09c-41c9-b21d-c858e0c37320" in namespace "var-expansion-3741"
I0521 09:02:10.328] May 21 09:01:00.822: INFO: Wait up to 5m0s for pod "var-expansion-c479a9b2-f09c-41c9-b21d-c858e0c37320" to be fully deleted
I0521 09:02:10.328] [AfterEach] [k8s.io] Variable Expansion
I0521 09:02:10.328]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:150
I0521 09:02:10.328] May 21 09:01:08.837: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready
... skipping 2 lines ...
I0521 09:02:10.329] May 21 09:01:14.899: INFO: namespace var-expansion-3741 deletion completed in 6.059964202s
I0521 09:02:10.329] 
I0521 09:02:10.329] 
I0521 09:02:10.329] • [SLOW TEST:134.122 seconds]
I0521 09:02:10.329] [k8s.io] Variable Expansion
I0521 09:02:10.329] /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:691
I0521 09:02:10.330]   should fail substituting values in a volume subpath with backticks [sig-storage][NodeFeature:VolumeSubpathEnvExpansion][Slow]
I0521 09:02:10.330]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/common/expansion.go:222
I0521 09:02:10.330] ------------------------------
I0521 09:02:10.330] [BeforeEach] [k8s.io] Variable Expansion
I0521 09:02:10.330]   /go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:149
I0521 09:02:10.330] STEP: Creating a kubernetes client
I0521 09:02:10.330] STEP: Building a namespace api object, basename var-expansion
... skipping 49 lines ...
I0521 09:02:10.336] I0521 09:02:04.836744    2472 services.go:157] Get log file "cloud-init.log" with journalctl command [-u cloud*].
I0521 09:02:10.336] I0521 09:02:04.844176    2472 services.go:157] Get log file "docker.log" with journalctl command [-u docker].
I0521 09:02:10.336] I0521 09:02:04.851569    2472 e2e_node_suite_test.go:191] Tests Finished
I0521 09:02:10.336] 
I0521 09:02:10.336] 
I0521 09:02:10.337] Ran 39 of 303 Specs in 308.404 seconds
I0521 09:02:10.337] SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 264 Skipped
I0521 09:02:10.337] 
I0521 09:02:10.337] 
I0521 09:02:10.337] Ginkgo ran 1 suite in 5m10.948552076s
I0521 09:02:10.337] Test Suite Passed
I0521 09:02:10.337] 
I0521 09:02:10.337] Success Finished Test Suite on Host tmp-node-e2e-bd1040f3-ubuntu-gke-1804-d1703-0-v20181113
... skipping 6 lines ...
W0521 09:02:10.683] 2019/05/21 09:02:10 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 10m31.320693774s
W0521 09:02:10.683] 2019/05/21 09:02:10 node.go:42: Noop - Node DumpClusterLogs() - /workspace/_artifacts: 
W0521 09:02:10.683] 2019/05/21 09:02:10 node.go:52: Noop - Node Down()
W0521 09:02:10.684] 2019/05/21 09:02:10 process.go:96: Saved XML output to /workspace/_artifacts/junit_runner.xml.
W0521 09:02:10.685] 2019/05/21 09:02:10 process.go:153: Running: bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"
W0521 09:02:11.016] 2019/05/21 09:02:11 process.go:155: Step 'bash -c . hack/lib/version.sh && KUBE_ROOT=. kube::version::get_version_vars && echo "${KUBE_GIT_VERSION-}"' finished in 331.334597ms
W0521 09:02:11.016] 2019/05/21 09:02:11 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]
W0521 09:02:11.021] Traceback (most recent call last):
W0521 09:02:11.022]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 778, in <module>
W0521 09:02:11.022]     main(parse_args())
W0521 09:02:11.022]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 626, in main
W0521 09:02:11.022]     mode.start(runner_args)
W0521 09:02:11.022]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 262, in start
W0521 09:02:11.022]     check_env(env, self.command, *args)
W0521 09:02:11.022]   File "/workspace/./test-infra/jenkins/../scenarios/kubernetes_e2e.py", line 111, in check_env
W0521 09:02:11.023]     subprocess.check_call(cmd, env=env)
W0521 09:02:11.023]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W0521 09:02:11.023]     raise CalledProcessError(retcode, cmd)
W0521 09:02:11.023] 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
E0521 09:02:11.033] Command failed
I0521 09:02:11.033] process 309 exited with code 1 after 10.6m
E0521 09:02:11.034] FAIL: ci-kubernetes-node-kubelet-features-beta
I0521 09:02:11.034] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W0521 09:02:11.693] Activated service account credentials for: [pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com]
I0521 09:02:11.758] process 38504 exited with code 0 after 0.0m
I0521 09:02:11.758] Call:  gcloud config get-value account
I0521 09:02:12.121] process 38516 exited with code 0 after 0.0m
I0521 09:02:12.121] Will upload results to gs://kubernetes-jenkins/logs using pr-kubekins@kubernetes-jenkins-pull.iam.gserviceaccount.com
I0521 09:02:12.121] Upload result and artifacts...
I0521 09:02:12.121] Gubernator results at https://gubernator.k8s.io/build/kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130757715677679616
I0521 09:02:12.122] Call:  gsutil ls gs://kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130757715677679616/artifacts
W0521 09:02:13.310] CommandException: One or more URLs matched no objects.
E0521 09:02:13.455] Command failed
I0521 09:02:13.455] process 38528 exited with code 1 after 0.0m
W0521 09:02:13.456] Remote dir gs://kubernetes-jenkins/logs/ci-kubernetes-node-kubelet-features-beta/1130757715677679616/artifacts not exist yet
I0521 09:02:13.456] 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/1130757715677679616/artifacts
I0521 09:02:16.268] process 38670 exited with code 0 after 0.0m
I0521 09:02:16.269] Call:  git rev-parse HEAD
I0521 09:02:16.274] process 39314 exited with code 0 after 0.0m
... skipping 13 lines ...