This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 1 failed / 6 succeeded
Started2020-03-18 11:19
Elapsed7m18s
Revisionrelease-1.17
links{u'resultstore': {u'url': u'https://source.cloud.google.com/results/invocations/7f6f3914-18e3-4d02-a380-810d6b535fa4/targets/test'}}
resultstorehttps://source.cloud.google.com/results/invocations/7f6f3914-18e3-4d02-a380-810d6b535fa4/targets/test

Test Failures


task-03-init 5m0s

timeout. task did not completed in less than 5m0s as expected
				from junit_runner.xml

Filter through log files | View test history on testgrid


Show 6 Passed Tests

Show 4 Skipped Tests

Error lines from build-log.txt

... skipping 239 lines ...
Created symlink /etc/systemd/system/multi-user.target.wants/kubelet.service → /kind/systemd/kubelet.service.
Created symlink /etc/systemd/system/kubelet.service → /kind/systemd/kubelet.service.
time="11:20:34" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e mkdir -p /etc/systemd/system/kubelet.service.d]"
time="11:20:35" level=info msg="Adding /etc/systemd/system/kubelet.service.d/10-kubeadm.conf to the image"
time="11:20:35" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e cp /alter/bits/systemd/10-kubeadm.conf /etc/systemd/system/kubelet.service.d/10-kubeadm.conf]"
time="11:20:35" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e chown -R root:root /etc/systemd/system/kubelet.service.d/10-kubeadm.conf]"
time="11:20:35" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e /bin/sh -c echo \"KUBELET_EXTRA_ARGS=--fail-swap-on=false\" >> /etc/default/kubelet]"
time="11:20:36" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e /bin/sh -c which docker || true]"
time="11:20:36" level=info msg="Detected containerd as container runtime"
time="11:20:36" level=info msg="Pre loading images ..."
time="11:20:36" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e mkdir -p /kind/images]"
time="11:20:36" level=debug msg="Running: [docker exec kind-build-5846e07a-9a43-42bc-84ac-3d49bd94af1e bash -c containerd & find /kind/images -name *.tar -print0 | xargs -r -0 -n 1 -P $(nproc) ctr --namespace=k8s.io images import --no-unpack && kill %1 && rm -rf /kind/images/*]"
time="2020-03-18T11:20:36.858956779Z" level=info msg="starting containerd" revision=7af311b4200b464a79c340b4e3a2799f8906ee8d version=v1.3.0-20-g7af311b4
time="2020-03-18T11:20:36.891668600Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." type=io.containerd.content.v1
time="2020-03-18T11:20:36.892011114Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.devmapper\"..." type=io.containerd.snapshotter.v1
time="2020-03-18T11:20:36.894420838Z" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.devmapper" error="devmapper not configured"
time="2020-03-18T11:20:36.894570490Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.native\"..." type=io.containerd.snapshotter.v1
time="2020-03-18T11:20:36.894760982Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." type=io.containerd.snapshotter.v1
time="2020-03-18T11:20:36.895112989Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." type=io.containerd.metadata.v1
time="2020-03-18T11:20:36.895246885Z" level=warning msg="could not use snapshotter devmapper in metadata plugin" error="devmapper not configured"
time="2020-03-18T11:20:36.895281101Z" level=info msg="metadata content store policy set" policy=shared
time="2020-03-18T11:20:36.902177310Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." type=io.containerd.differ.v1
time="2020-03-18T11:20:36.902218768Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." type=io.containerd.gc.v1
time="2020-03-18T11:20:36.902305798Z" level=info msg="loading plugin \"io.containerd.service.v1.containers-service\"..." type=io.containerd.service.v1
time="2020-03-18T11:20:36.902340507Z" level=info msg="loading plugin \"io.containerd.service.v1.content-service\"..." type=io.containerd.service.v1
time="2020-03-18T11:20:36.902364992Z" level=info msg="loading plugin \"io.containerd.service.v1.diff-service\"..." type=io.containerd.service.v1
... skipping 20 lines ...
time="2020-03-18T11:20:36.904456124Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." type=io.containerd.grpc.v1
time="2020-03-18T11:20:36.904477827Z" level=info msg="loading plugin \"io.containerd.grpc.v1.cri\"..." type=io.containerd.grpc.v1
time="2020-03-18T11:20:36.904704828Z" level=info msg="Start cri plugin with config {PluginConfig:{ContainerdConfig:{Snapshotter:overlayfs DefaultRuntimeName:runc DefaultRuntime:{Type:io.containerd.runc.v2 Engine: PodAnnotations:[] Root: Options:<nil> PrivilegedWithoutHostDevices:false} UntrustedWorkloadRuntime:{Type: Engine: PodAnnotations:[] Root: Options:<nil> PrivilegedWithoutHostDevices:false} Runtimes:map[runc:{Type:io.containerd.runc.v1 Engine: PodAnnotations:[] Root: Options:<nil> PrivilegedWithoutHostDevices:false} test-handler:{Type:io.containerd.runc.v2 Engine: PodAnnotations:[] Root: Options:<nil> PrivilegedWithoutHostDevices:false}] NoPivot:false} CniConfig:{NetworkPluginBinDir:/opt/cni/bin NetworkPluginConfDir:/etc/cni/net.d NetworkPluginMaxConfNum:1 NetworkPluginConfTemplate:} Registry:{Mirrors:map[docker.io:{Endpoints:[https://registry-1.docker.io]}] Configs:map[] Auths:map[]} DisableTCPService:true StreamServerAddress:127.0.0.1 StreamServerPort:0 StreamIdleTimeout:4h0m0s EnableSelinux:false SandboxImage:k8s.gcr.io/pause:3.1 StatsCollectPeriod:10 SystemdCgroup:false EnableTLSStreaming:false X509KeyPairStreaming:{TLSCertFile: TLSKeyFile:} MaxContainerLogLineSize:16384 DisableCgroup:false DisableApparmor:false RestrictOOMScoreAdj:false MaxConcurrentDownloads:3 DisableProcMount:false} ContainerdRootDir:/var/lib/containerd ContainerdEndpoint:/run/containerd/containerd.sock RootDir:/var/lib/containerd/io.containerd.grpc.v1.cri StateDir:/run/containerd/io.containerd.grpc.v1.cri}"
time="2020-03-18T11:20:36.904761897Z" level=warning msg="`default_runtime` is deprecated, please use `default_runtime_name` to reference the default configuration you have defined in `runtimes`"
time="2020-03-18T11:20:36.904862513Z" level=info msg="Connect containerd service"
time="2020-03-18T11:20:36.905122724Z" level=info msg="Get image filesystem path \"/var/lib/containerd/io.containerd.snapshotter.v1.overlayfs\""
time="2020-03-18T11:20:36.905424462Z" level=error msg="Failed to load cni during init, please check CRI plugin status before setting up network for pods" error="cni config load failed: no network config found in /etc/cni/net.d: cni plugin not initialized: failed to load cni config"
time="2020-03-18T11:20:36.905740269Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." type=io.containerd.grpc.v1
time="2020-03-18T11:20:36.905909512Z" level=info msg="Start subscribing containerd event"
time="2020-03-18T11:20:36.906003362Z" level=info msg="Start recovering state"
time="2020-03-18T11:20:36.906261026Z" level=info msg="Start event monitor"
time="2020-03-18T11:20:36.906309412Z" level=info msg="Start snapshots syncer"
time="2020-03-18T11:20:36.906320049Z" level=info msg=serving... address=/run/containerd/containerd.sock.ttrpc
time="2020-03-18T11:20:36.906325691Z" level=info msg="Start streaming server"
time="2020-03-18T11:20:36.906427283Z" level=info msg=serving... address=/run/containerd/containerd.sock
time="2020-03-18T11:20:36.906460344Z" level=info msg="containerd successfully booted in 0.048851s"
time="2020-03-18T11:20:39.051548872Z" level=error msg="(*service).Write failed" error="rpc error: code = Unavailable desc = ref k8s.io/1/tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/layer.tar locked: unavailable" ref=tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/layer.tar total=53882368
time="2020-03-18T11:20:41.845481557Z" level=error msg="(*service).Write failed" error="rpc error: code = Unavailable desc = ref k8s.io/1/tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/VERSION locked: unavailable" ref=tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/VERSION total=3
time="2020-03-18T11:20:42.632777611Z" level=error msg="(*service).Write failed" error="rpc error: code = Unavailable desc = ref k8s.io/1/tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/layer.tar locked: unavailable" ref=tar-7642396919f26df99df1ff78e89004e3ef88e4c470e96082598862bcd55d68d2/layer.tar total=53882368
time="2020-03-18T11:20:42.906459075Z" level=info msg="ImageCreate event &ImageCreate{Name:k8s.gcr.io/kube-scheduler:v1.17.5-beta.0.11_4dfcd1cc87879f,Labels:map[string]string{},XXX_unrecognized:[],}"
time="2020-03-18T11:20:42.920286761Z" level=info msg="ImageCreate event &ImageCreate{Name:sha256:cd8312b29d3f99e745646a661ef7f2b84a7f37964fea38d6a542f8bf8f57affd,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2020-03-18T11:20:42.920930623Z" level=info msg="ImageUpdate event &ImageUpdate{Name:k8s.gcr.io/kube-scheduler:v1.17.5-beta.0.11_4dfcd1cc87879f,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2020-03-18T11:20:42.941829408Z" level=info msg="ImageCreate event &ImageCreate{Name:k8s.gcr.io/kube-controller-manager:v1.17.5-beta.0.11_4dfcd1cc87879f,Labels:map[string]string{},XXX_unrecognized:[],}"
time="2020-03-18T11:20:42.952477051Z" level=info msg="ImageCreate event &ImageCreate{Name:sha256:79cc419bc06224a61073fbe7b66b30691dc4b2e85ce5238bfd1c9d519a7c6d97,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
time="2020-03-18T11:20:42.953288944Z" level=info msg="ImageUpdate event &ImageUpdate{Name:k8s.gcr.io/kube-controller-manager:v1.17.5-beta.0.11_4dfcd1cc87879f,Labels:map[string]string{io.cri-containerd.image: managed,},XXX_unrecognized:[],}"
... skipping 109 lines ...
time="11:21:45" level=debug msg="Running: /usr/bin/docker [docker inspect -f {{range .NetworkSettings.Networks}}{{.IPAddress}},{{.GlobalIPv6Address}}{{end}} kinder-regular-lb]"

kinder-regular-control-plane-1:$ Preparing /kind/kubeadm.conf
time="11:21:45" level=debug msg="Running: /usr/bin/docker [docker inspect -f {{range .NetworkSettings.Networks}}{{.IPAddress}},{{.GlobalIPv6Address}}{{end}} kinder-regular-control-plane-1]"
time="11:21:45" level=debug msg="Running: [docker exec kinder-regular-control-plane-1 kubeadm version -o=short]"
time="11:21:45" level=debug msg="Preparing kubeadm config v1beta2 (kubeadm version 1.17.5-beta.0.11+4dfcd1cc87879f)"
time="11:21:45" level=debug msg="generated config:\napiServer:\n  certSANs:\n  - localhost\n  - 172.17.0.2\napiVersion: kubeadm.k8s.io/v1beta2\nclusterName: kinder-regular\ncontrolPlaneEndpoint: 172.17.0.7:6443\ncontrollerManager:\n  extraArgs:\n    enable-hostpath-provisioner: \"true\"\nkind: ClusterConfiguration\nkubernetesVersion: v1.17.5-beta.0.11+4dfcd1cc87879f\nnetworking:\n  podSubnet: 192.168.0.0/16\n  serviceSubnet: \"\"\nscheduler:\n  extraArgs: null\n---\napiVersion: kubeadm.k8s.io/v1beta2\nbootstrapTokens:\n- token: abcdef.0123456789abcdef\nkind: InitConfiguration\nlocalAPIEndpoint:\n  advertiseAddress: 172.17.0.2\n  bindPort: 6443\nnodeRegistration:\n  criSocket: /run/containerd/containerd.sock\n  kubeletExtraArgs:\n    fail-swap-on: \"false\"\n    node-ip: 172.17.0.2\n---\napiVersion: kubelet.config.k8s.io/v1beta1\nevictionHard:\n  imagefs.available: 0%\n  nodefs.available: 0%\n  nodefs.inodesFree: 0%\nimageGCHighThresholdPercent: 100\nkind: KubeletConfiguration\n---\napiVersion: kubeproxy.config.k8s.io/v1alpha1\nkind: KubeProxyConfiguration\n"
time="11:21:45" level=debug msg="Running: [docker cp /tmp/kinder-regular-control-plane-1-772206008 kinder-regular-control-plane-1:/kind/kubeadm.conf]"

kinder-regular-lb:$ Updating load balancer configuration with 1 control plane backends
time="11:21:46" level=debug msg="Running: /usr/bin/docker [docker inspect -f {{range .NetworkSettings.Networks}}{{.IPAddress}},{{.GlobalIPv6Address}}{{end}} kinder-regular-control-plane-1]"
time="11:21:46" level=debug msg="Writing loadbalancer config on kinder-regular-lb..."
time="11:21:46" level=debug msg="Running: [docker cp /tmp/kinder-regular-lb-356696503 kinder-regular-lb:/usr/local/etc/haproxy/haproxy.cfg]"
... skipping 31 lines ...
I0318 11:21:47.130212     172 checks.go:376] validating the presence of executable ebtables
I0318 11:21:47.130378     172 checks.go:376] validating the presence of executable ethtool
I0318 11:21:47.130435     172 checks.go:376] validating the presence of executable socat
I0318 11:21:47.130492     172 checks.go:376] validating the presence of executable tc
I0318 11:21:47.130526     172 checks.go:376] validating the presence of executable touch
I0318 11:21:47.130572     172 checks.go:520] running all checks
[preflight] The system verification failed. Printing the output from the verification:
KERNEL_VERSION: 4.15.0-1044-gke
OS: Linux
CGROUPS_CPU: enabled
CGROUPS_CPUACCT: enabled
CGROUPS_CPUSET: enabled
CGROUPS_DEVICES: enabled
CGROUPS_FREEZER: enabled
CGROUPS_MEMORY: enabled
	[WARNING SystemVerification]: failed to parse kernel config: unable to load kernel module: "configs", output: "modprobe: FATAL: Module configs not found in directory /lib/modules/4.15.0-1044-gke\n", err: exit status 1
I0318 11:21:47.139743     172 checks.go:406] checking whether the given node name is reachable using net.LookupHost
I0318 11:21:47.140016     172 checks.go:618] validating kubelet version
I0318 11:21:47.226791     172 checks.go:128] validating if the service is enabled and active
I0318 11:21:47.239623     172 checks.go:201] validating availability of port 10250
I0318 11:21:47.239750     172 checks.go:201] validating availability of port 2379
I0318 11:21:47.239792     172 checks.go:201] validating availability of port 2380
... skipping 109 lines ...
W0318 11:26:48.404675     692 removeetcdmember.go:79] [reset] No kubeadm config, using etcd pod spec to get data directory
[preflight] Running pre-flight checks
[reset] No etcd config found. Assuming external etcd
[reset] Please, manually reset etcd to prevent further issues
[reset] Stopping the kubelet service
I0318 11:26:48.404840     692 cleanupnode.go:57] [reset] Getting init system
W0318 11:26:48.410506     692 cleanupnode.go:99] [reset] Failed to evaluate the "/var/lib/kubelet" directory. Skipping its unmount and cleanup: lstat /var/lib/kubelet: no such file or directory
I0318 11:26:48.410522     692 cleanupnode.go:79] [reset] Removing Kubernetes-managed containers
[reset] Unmounting mounted directories in "/var/lib/kubelet"
I0318 11:26:48.423793     692 cleanupnode.go:87] [reset] Removing contents from the config and pki directories
I0318 11:26:48.423916     692 reset.go:218] [reset] Deleting content of /var/lib/dockershim
I0318 11:26:48.423929     692 reset.go:218] [reset] Deleting content of /var/run/kubernetes
I0318 11:26:48.423937     692 reset.go:218] [reset] Deleting content of /var/lib/cni
... skipping 21 lines ...
I0318 11:26:48.748827     499 cleanupnode.go:57] [reset] Getting init system
[preflight] Running pre-flight checks
[reset] No etcd config found. Assuming external etcd
[reset] Please, manually reset etcd to prevent further issues
[reset] Stopping the kubelet service
[reset] Unmounting mounted directories in "/var/lib/kubelet"
W0318 11:26:48.755412     499 cleanupnode.go:99] [reset] Failed to evaluate the "/var/lib/kubelet" directory. Skipping its unmount and cleanup: lstat /var/lib/kubelet: no such file or directory
I0318 11:26:48.755441     499 cleanupnode.go:79] [reset] Removing Kubernetes-managed containers
[reset] Deleting contents of config directories: [/etc/kubernetes/manifests /etc/kubernetes/pki]
[reset] Deleting files: [/etc/kubernetes/admin.conf /etc/kubernetes/kubelet.conf /etc/kubernetes/bootstrap-kubelet.conf /etc/kubernetes/controller-manager.conf /etc/kubernetes/scheduler.conf]
[reset] Deleting contents of stateful directories: [/var/lib/dockershim /var/run/kubernetes /var/lib/cni]
I0318 11:26:48.765679     499 cleanupnode.go:87] [reset] Removing contents from the config and pki directories
I0318 11:26:48.765830     499 reset.go:218] [reset] Deleting content of /var/lib/dockershim
... skipping 19 lines ...
W0318 11:26:49.091248     504 removeetcdmember.go:79] [reset] No kubeadm config, using etcd pod spec to get data directory
I0318 11:26:49.091280     504 cleanupnode.go:57] [reset] Getting init system
[preflight] Running pre-flight checks
[reset] No etcd config found. Assuming external etcd
[reset] Please, manually reset etcd to prevent further issues
[reset] Stopping the kubelet service
W0318 11:26:49.095988     504 cleanupnode.go:99] [reset] Failed to evaluate the "/var/lib/kubelet" directory. Skipping its unmount and cleanup: lstat /var/lib/kubelet: no such file or directory
I0318 11:26:49.096005     504 cleanupnode.go:79] [reset] Removing Kubernetes-managed containers
[reset] Unmounting mounted directories in "/var/lib/kubelet"
[reset] Deleting contents of config directories: [/etc/kubernetes/manifests /etc/kubernetes/pki]
[reset] Deleting files: [/etc/kubernetes/admin.conf /etc/kubernetes/kubelet.conf /etc/kubernetes/bootstrap-kubelet.conf /etc/kubernetes/controller-manager.conf /etc/kubernetes/scheduler.conf]
[reset] Deleting contents of stateful directories: [/var/lib/dockershim /var/run/kubernetes /var/lib/cni]

... skipping 20 lines ...
W0318 11:26:49.429506     511 removeetcdmember.go:79] [reset] No kubeadm config, using etcd pod spec to get data directory
I0318 11:26:49.429538     511 cleanupnode.go:57] [reset] Getting init system
[preflight] Running pre-flight checks
[reset] No etcd config found. Assuming external etcd
[reset] Please, manually reset etcd to prevent further issues
[reset] Stopping the kubelet service
W0318 11:26:49.435529     511 cleanupnode.go:99] [reset] Failed to evaluate the "/var/lib/kubelet" directory. Skipping its unmount and cleanup: lstat /var/lib/kubelet: no such file or directory
I0318 11:26:49.435542     511 cleanupnode.go:79] [reset] Removing Kubernetes-managed containers
[reset] Unmounting mounted directories in "/var/lib/kubelet"
[reset] Deleting contents of config directories: [/etc/kubernetes/manifests /etc/kubernetes/pki]
[reset] Deleting files: [/etc/kubernetes/admin.conf /etc/kubernetes/kubelet.conf /etc/kubernetes/bootstrap-kubelet.conf /etc/kubernetes/controller-manager.conf /etc/kubernetes/scheduler.conf]
I0318 11:26:49.446013     511 cleanupnode.go:87] [reset] Removing contents from the config and pki directories
I0318 11:26:49.446234     511 reset.go:218] [reset] Deleting content of /var/lib/dockershim
... skipping 21 lines ...
I0318 11:26:49.780036     513 cleanupnode.go:57] [reset] Getting init system
[preflight] Running pre-flight checks
[reset] No etcd config found. Assuming external etcd
[reset] Please, manually reset etcd to prevent further issues
[reset] Stopping the kubelet service
[reset] Unmounting mounted directories in "/var/lib/kubelet"
W0318 11:26:49.786144     513 cleanupnode.go:99] [reset] Failed to evaluate the "/var/lib/kubelet" directory. Skipping its unmount and cleanup: lstat /var/lib/kubelet: no such file or directory
I0318 11:26:49.786164     513 cleanupnode.go:79] [reset] Removing Kubernetes-managed containers
I0318 11:26:49.796190     513 cleanupnode.go:87] [reset] Removing contents from the config and pki directories
I0318 11:26:49.796389     513 reset.go:218] [reset] Deleting content of /var/lib/dockershim
I0318 11:26:49.796411     513 reset.go:218] [reset] Deleting content of /var/run/kubernetes
[reset] Deleting contents of config directories: [/etc/kubernetes/manifests /etc/kubernetes/pki]
[reset] Deleting files: [/etc/kubernetes/admin.conf /etc/kubernetes/kubelet.conf /etc/kubernetes/bootstrap-kubelet.conf /etc/kubernetes/controller-manager.conf /etc/kubernetes/scheduler.conf]
... skipping 19 lines ...
Deleting cluster "kinder-regular" ...
time="11:26:50" level=debug msg="Running: /usr/bin/docker [docker ps -q -a --no-trunc --filter label=io.k8s.sigs.kind.cluster --format {{.Names}}\\t{{.Label \"io.k8s.sigs.kind.cluster\"}} --filter label=io.k8s.sigs.kind.cluster=kinder-regular]"
time="11:26:50" level=debug msg="Running: /usr/bin/docker [docker rm -f -v kinder-regular-lb kinder-regular-worker-1 kinder-regular-control-plane-1 kinder-regular-control-plane-2 kinder-regular-control-plane-3 kinder-regular-worker-2]"
 completed!

Ran 7 of 11 tasks in 0.000 seconds
FAIL! -- 6 tasks Passed | 1 Failed | 4 Skipped

see junit-runner.xml and task logs files for more details

Error: failed executing the workflow
+ EXIT_VALUE=1
+ set +o xtrace
Cleaning up after docker in docker.
================================================================================
Cleaning up binfmt_misc ...
================================================================================
... skipping 2 lines ...