Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

kubelet warnings flooding systemd logs (kube 1.14.1 with CentOS packages) #76531

Open
elishemer opened this Issue Apr 13, 2019 · 7 comments

Comments

Projects
None yet
7 participants
@elishemer
Copy link

elishemer commented Apr 13, 2019

What happened:
there are many kubelet warnings in the systemd logs

Apr 13 03:37:29 env003master1 kubelet[28028]: W0413 03:37:29.272201 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_29844_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_29844_systemd_test_default.slice: no such file or directory
Apr 13 03:37:29 env003master1 kubelet[28028]: W0413 03:37:29.312230 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_29849_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:29 env003master1 kubelet[28028]: W0413 03:37:29.312298 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_29849_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_29849_systemd_test_default.slice: no such file or directory
Apr 13 03:37:39 env003master1 kubelet[28028]: W0413 03:37:39.459059 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_30784_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:39 env003master1 kubelet[28028]: W0413 03:37:39.459165 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_30784_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_30784_systemd_test_default.slice: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.071477 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/cpu,cpuacct/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/cpu,cpuacct/libcontainer_32125_systemd_test_default.slice: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.071538 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/blkio/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/blkio/libcontainer_32125_systemd_test_default.slice: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.086871 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.087413 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_32125_systemd_test_default.slice: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.113291 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:56 env003master1 kubelet[28028]: W0413 03:37:56.113357 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_32125_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_32125_systemd_test_default.slice: no such file or directory
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129072 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129117 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.memsw.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.memsw.limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129144 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.soft_limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.soft_limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129207 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129226 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.memsw.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.memsw.limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.129243 28028 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.soft_limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice/memory.soft_limit_in_bytes: no such device
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.131117 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_32168_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.131166 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_32168_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_32168_systemd_test_default.slice: no such file or directory
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.209252 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_32183_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.209319 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_32183_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_32183_systemd_test_default.slice: no such file or directory
Apr 13 03:37:59 env003master1 kubelet[28028]: W0413 03:37:59.314966 28028 container.go:523] Failed to update stats for container "/libcontainer_32206_systemd_test_default.slice": failed to parse memory.kmem.tcp.failcnt - read /sys/fs/cgroup/memory/libcontainer_32206_systemd_test_default.slice/memory.kmem.tcp.failcnt: no such device, continuing to push stats
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.571579 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_511_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.571640 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_511_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_511_systemd_test_default.slice: no such file or directory
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.632172 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_516_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.632227 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_516_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_516_systemd_test_default.slice: no such file or directory
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.715124 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_536_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 13 03:38:05 env003master1 kubelet[28028]: W0413 03:38:05.715197 28028 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_536_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): open /sys/fs/cgroup/devices/libcontainer_536_systemd_test_default.slice: no such file or directory

and I initialized the kubernetes with kubeadm init

What you expected to happen:
Not to have many kubelet errors in the systemd logs

How to reproduce it (as minimally and precisely as possible):
yum install kubernetes packages on centos
kubeadm init

Anything else we need to know?:
cgroup driver is set on systemd

Environment:

  • Kubernetes version - 1.14.1
    docker-ce-18.09.4-3.el7.x86_64
  • Cloud provider or hardware configuration - VM on baremetal Xen server
  • OS (e.g: cat /etc/os-release): [root@env003master1 ~]# cat /etc/redhat-release
    CentOS Linux release 7.6.1810 (Core)
  • Kernel (e.g. uname -a): Linux env003master1 3.10.0-957.5.1.el7.x86_64 #1 SMP Fri Feb 1 14:54:57 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
  • Install tools: yum install and kubeadm init
  • Others:
@elishemer

This comment has been minimized.

Copy link
Author

elishemer commented Apr 13, 2019

/sig node

@k8s-ci-robot k8s-ci-robot added sig/node and removed needs-sig labels Apr 13, 2019

@mattjmcnaughton

This comment has been minimized.

Copy link
Contributor

mattjmcnaughton commented Apr 14, 2019

Thanks for reporting!

Two high level questions: can you share the outputs of ls sys/fs/cgroup/devices? Additionally, I'm curious if you're finding *_systemd_test_default.slice files anywhere on your system? You could use find / -type f -name "*_systemd_test_default.slice" to explore.

@elishemer

This comment has been minimized.

Copy link
Author

elishemer commented Apr 15, 2019

@mattjmcnaughton

[root@env003master1 ~]# ls /sys/fs/cgroup/devices
cgroup.clone_children cgroup.procs devices.allow devices.list notify_on_release system.slice user.slice
cgroup.event_control cgroup.sane_behavior devices.deny kubepods.slice release_agent tasks
[root@env003master1 ~]# find / -type f -name "*_systemd_test_default.slice"
find: ‘/proc/3197’: No such file or directory

[root@env003master1 ~]#

@sudy1

This comment has been minimized.

Copy link

sudy1 commented Apr 16, 2019

I have the same problem, how to fix ?

@krisdock

This comment has been minimized.

Copy link

krisdock commented Apr 17, 2019

Seeing the same on Bionic.

DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=18.04
DISTRIB_CODENAME=bionic
DISTRIB_DESCRIPTION="Ubuntu 18.04.2 LTS"
@fl-max

This comment has been minimized.

Copy link

fl-max commented Apr 18, 2019

I am experiencing the same issue

OS

# cat /etc/centos-release
CentOS Linux release 7.4.1708 (Core)
# uname -r
3.10.0-693.11.1.el7.x86_64
# getenforce
Permissive
# cat /etc/selinux/config | grep SELINUX=
SELINUX=permissive
# ls /sys/fs/cgroup/devices
cgroup.clone_children  cgroup.procs          devices.allow  devices.list  kubepods.slice     release_agent  tasks
cgroup.event_control   cgroup.sane_behavior  devices.deny   init.scope    notify_on_release  system.slice   user.slice
# find / -type f -name "*_systemd_test_default.slice"
<empty>

Docker

# docker info
Containers: 18
 Running: 16
 Paused: 0
 Stopped: 2
Images: 8
Server Version: 18.09.4
Storage Driver: overlay2
 Backing Filesystem: xfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: systemd
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: bb71b10fd8f58240ca47fbb579b9d1028eea7c84
runc version: 2b18fe1d885ee5083ef9f0838fee39b62d653e30
init version: fec3683
Security Options:
 seccomp
  Profile: default
Kernel Version: 3.10.0-693.11.1.el7.x86_64
Operating System: CentOS Linux 7 (Core)
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 7.781GiB

Kubelet

# cat /etc/kubernetes/config.yaml
...
apiVersion: kubelet.config.k8s.io/v1beta1
kind: KubeletConfiguration
cgroupDriver: systemd
# service kubelet status -l
Redirecting to /bin/systemctl status  -l kubelet.service
● kubelet.service - kubelet: The Kubernetes Node Agent
   Loaded: loaded (/usr/lib/systemd/system/kubelet.service; enabled; vendor preset: disabled)
  Drop-In: /usr/lib/systemd/system/kubelet.service.d
           └─10-kubeadm.conf
   Active: active (running) since Thu 2019-04-18 16:23:10 UTC; 1min 40s ago
     Docs: https://kubernetes.io/docs/
 Main PID: 43914 (kubelet)
    Tasks: 20
   Memory: 30.9M
   CGroup: /system.slice/kubelet.service
           └─43914 /usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --allow-privileged=true --cgroup-driver=systemd --cloud-config=/etc/kubernetes/azure.json --cloud-provider=azure --max-pods=30 --network-plugin=cni --node-labels=kubernetes.io/role=master,kubernetes.azure.com/cluster=dap-qa-qa --pod-infra-container-image=k8s.gcr.io/pause:3.1 --cloud-provider=azure --cloud-config=/etc/kubernetes/azure.json --node-ip=10.224.89.239

Apr 18 16:23:12 dap-qa-qa-k8smaster-0 kubelet[43914]: I0418 16:23:12.649758   43914 reconciler.go:207] operationExecutor.VerifyControllerAttachedVolume started for volume "k8s-certs" (UniqueName: "kubernetes.io/host-path/be6d57ac4334e109bfa2a1592ed92a32-k8s-certs") pod "kube-controller-manager-dap-qa-qa-k8smaster-0" (UID: "be6d57ac4334e109bfa2a1592ed92a32")
Apr 18 16:23:12 dap-qa-qa-k8smaster-0 kubelet[43914]: I0418 16:23:12.851076   43914 reconciler.go:154] Reconciler: start to sync state
Apr 18 16:24:09 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:09.854662   43914 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.limit_in_bytes: no such device
Apr 18 16:24:09 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:09.854737   43914 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.memsw.limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.memsw.limit_in_bytes: no such device
Apr 18 16:24:09 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:09.854804   43914 helpers.go:137] readString: Failed to read "/sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.soft_limit_in_bytes": read /sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.soft_limit_in_bytes: no such device
Apr 18 16:24:09 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:09.855075   43914 container.go:523] Failed to update stats for container "/libcontainer_44426_systemd_test_default.slice": failed to parse memory.usage_in_bytes - read /sys/fs/cgroup/memory/libcontainer_44426_systemd_test_default.slice/memory.usage_in_bytes: no such device, continuing to push stats
Apr 18 16:24:10 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:10.303109   43914 raw.go:87] Error while processing event ("/sys/fs/cgroup/cpu,cpuacct/libcontainer_44478_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/cpu,cpuacct/libcontainer_44478_systemd_test_default.slice: no such file or directory
Apr 18 16:24:10 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:10.303296   43914 raw.go:87] Error while processing event ("/sys/fs/cgroup/blkio/libcontainer_44478_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/blkio/libcontainer_44478_systemd_test_default.slice: no such file or directory
Apr 18 16:24:10 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:10.344529   43914 raw.go:87] Error while processing event ("/sys/fs/cgroup/memory/libcontainer_44478_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): readdirent: no such file or directory
Apr 18 16:24:10 dap-qa-qa-k8smaster-0 kubelet[43914]: W0418 16:24:10.344611   43914 raw.go:87] Error while processing event ("/sys/fs/cgroup/devices/libcontainer_44478_systemd_test_default.slice": 0x40000100 == IN_CREATE|IN_ISDIR): inotify_add_watch /sys/fs/cgroup/devices/libcontainer_44478_systemd_test_default.slice: no such file or directory

Things I've tried

  1. Enabling CPUAccounting & MemoryAccounting on the kubelet service based on this old thread
  2. Upgrading SystemD based on this comment
    Used this post to upgrade SystemD from v219 to v234
@yanghaichao12

This comment has been minimized.

Copy link
Contributor

yanghaichao12 commented Apr 20, 2019

@fl-max is it fixed after upgrading systemd?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.