{"action":"created","issue":{"url":"https://api.github.com/repos/kubernetes/kubernetes/issues/61999","repository_url":"https://api.github.com/repos/kubernetes/kubernetes","labels_url":"https://api.github.com/repos/kubernetes/kubernetes/issues/61999/labels{/name}","comments_url":"https://api.github.com/repos/kubernetes/kubernetes/issues/61999/comments","events_url":"https://api.github.com/repos/kubernetes/kubernetes/issues/61999/events","html_url":"https://github.com/kubernetes/kubernetes/issues/61999","id":310374493,"number":61999,"title":"Recurring high iowait due to kubelet 'du' process","user":{"login":"glennschmidt","id":1758170,"avatar_url":"https://avatars0.githubusercontent.com/u/1758170?v=4","gravatar_id":"","url":"https://api.github.com/users/glennschmidt","html_url":"https://github.com/glennschmidt","followers_url":"https://api.github.com/users/glennschmidt/followers","following_url":"https://api.github.com/users/glennschmidt/following{/other_user}","gists_url":"https://api.github.com/users/glennschmidt/gists{/gist_id}","starred_url":"https://api.github.com/users/glennschmidt/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/glennschmidt/subscriptions","organizations_url":"https://api.github.com/users/glennschmidt/orgs","repos_url":"https://api.github.com/users/glennschmidt/repos","events_url":"https://api.github.com/users/glennschmidt/events{/privacy}","received_events_url":"https://api.github.com/users/glennschmidt/received_events","type":"User","site_admin":false},"labels":[{"id":105146071,"url":"https://api.github.com/repos/kubernetes/kubernetes/labels/kind/bug","name":"kind/bug","color":"e11d21","default":false},{"id":173493665,"url":"https://api.github.com/repos/kubernetes/kubernetes/labels/sig/node","name":"sig/node","color":"d2b48c","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":2,"created_at":"2018-04-02T02:03:26Z","updated_at":"2018-04-19T16:31:17Z","closed_at":null,"author_association":"NONE","body":"/kind bug\r\n\r\n**What happened**:\r\n\r\nI'm using Kubernetes 1.8.7 installed on AWS with kops. Every now and again one of my nodes will enter a state where it becomes unable to measure overlay FS usage without causing extremely high IO wait. When this happens the host enters a loop which looks like this:\r\n1. Host load becomes very high and all workloads are affected for a few minutes\r\n2. Eventually the `du` processes start to time out with messages as shown below\r\n3. The host load recovers\r\n4. After a little while (between 2-20 minutes) it returns to step 1 and starts trying to run `du` again\r\n\r\nOnce this starts, it keeps repeating forever until I drain and replace the node.\r\n\r\nThe same symptoms are also described by another user in this comment:\r\nhttps://github.com/kubernetes/kubernetes/issues/23255#issuecomment-288351040\r\nHowever I can't find an open issue specifically for this, which is why i'm logging one.\r\n\r\n**Anything else we need to know?**:\r\n\r\nThe kubelet log is full of messages like this\r\n```\r\nfs.go:564] killing cmd [nice -n 19 du -s /var/lib/docker/overlay/bde4e4b217acb453858c9eed37cf088f3e01c64d56e8df94c7a4b4b4869e394f] due to timeout(2m0s)\r\nfsHandler.go:121] failed to collect filesystem stats - rootDiskErr: du command failed on /var/lib/docker/overlay/4e549e6b32509edf87ccc3c120484b88d26d79fa8a205ea64d3cf45d7f225672 with output stdout: , stderr:  - signal: killed, rootInodeErr: <nil>, extraDiskErr: <nil>\r\nfsHandler.go:131] du and find on following dirs took 2m3.835260669s: [/var/lib/docker/overlay/4e549e6b32509edf87ccc3c120484b88d26d79fa8a205ea64d3cf45d7f225672 /var/lib/docker/containers/1ba1422e4d78656cf9d3c1eee4e32511ada570369dadda7ff48733b80f330e1f]\r\nfsHandler.go:121] failed to collect filesystem stats - rootDiskErr: du command failed on /var/lib/docker/overlay/bde4e4b217acb453858c9eed37cf088f3e01c64d56e8df94c7a4b4b4869e394f with output stdout: , stderr:  - signal: killed, rootInodeErr: <nil>, extraDiskErr: <nil>\r\nfsHandler.go:131] du and find on following dirs took 2m2.80314731s: [/var/lib/docker/overlay/bde4e4b217acb453858c9eed37cf088f3e01c64d56e8df94c7a4b4b4869e394f /var/lib/docker/containers/73944dfc818609292fee83e86e1fcf1c89b92cbae00b0e250911027894de8a04]\r\nfs.go:564] killing cmd [nice -n 19 du -s /var/lib/docker/overlay/908e2f4855747319fd0451a4f62312eef69353239a1c4d4683f33032f42d31b4] due to timeout(2m0s)\r\nfsHandler.go:121] failed to collect filesystem stats - rootDiskErr: du command failed on /var/lib/docker/overlay/908e2f4855747319fd0451a4f62312eef69353239a1c4d4683f33032f42d31b4 with output stdout: , stderr:  - signal: killed, rootInodeErr: <nil>, extraDiskErr: <nil>\r\nfsHandler.go:131] du and find on following dirs took 2m1.195693546s: [/var/lib/docker/overlay/908e2f4855747319fd0451a4f62312eef69353239a1c4d4683f33032f42d31b4 /var/lib/docker/containers/7ecde624cd22d06af3b21c36a829d97b6e7f7a11e3cfa007fd72ada8fcf57d2a]\r\nsummary.go:92] Failed to get system container stats for \"/system.slice/kubelet.service\": failed to get cgroup stats for \"/system.slice/kubelet.service\": failed to get container info for \"/system.slice/kubelet.service\": unknown container \"/system.slice/kubelet.service\"\r\nsummary.go:92] Failed to get system container stats for \"/system.slice/docker.service\": failed to get cgroup stats for \"/system.slice/docker.service\": failed to get container info for \"/system.slice/docker.service\": unknown container \"/system.slice/docker.service\"\r\nfs.go:564] killing cmd [nice -n 19 du -s /var/lib/docker/overlay/927e65038a4aeb39c46461ed7ee2445495b2dba11dcb790bbe315e267da7ebe6] due to timeout(2m0s)\r\nfsHandler.go:121] failed to collect filesystem stats - rootDiskErr: du command failed on /var/lib/docker/overlay/927e65038a4aeb39c46461ed7ee2445495b2dba11dcb790bbe315e267da7ebe6 with output stdout: , stderr:  - signal: killed, rootInodeErr: <nil>, extraDiskErr: <nil>\r\nfsHandler.go:131] du and find on following dirs took 2m2.90814158s: [/var/lib/docker/overlay/927e65038a4aeb39c46461ed7ee2445495b2dba11dcb790bbe315e267da7ebe6 /var/lib/docker/containers/30fc57f794d5e957d6586802ff2a144a604551ae058e132c8bec875e0306873e]\r\n```\r\n\r\nIf I manually run `du` against one of the overlay directories that timed out in the log, it returns a result almost immediately\r\n```\r\n# du -s bde4e4b217acb453858c9eed37cf088f3e01c64d56e8df94c7a4b4b4869e394f\r\n824240\tbde4e4b217acb453858c9eed37cf088f3e01c64d56e8df94c7a4b4b4869e394f\r\n```\r\n\r\nAny suggestions about how to debug this are appreciated. I've tried to figure out which container filesystems are specifically causing the problem, but I'm not sure how to approach that, since I can't find any one particular `du` command line that hangs for a long time.\r\n\r\n**Environment**:\r\n- Kubernetes version (use `kubectl version`): 1.8.7\r\n- Cloud provider or hardware configuration: AWS\r\n- OS (e.g. from /etc/os-release): Debian Jessie\r\n- Kernel (e.g. `uname -a`): 4.4.115-k8s #1 SMP Thu Feb 8 15:37:40 UTC 2018 x86_64 GNU/Linux\r\n- Install tools: kops\r\n- Others:\r\n"},"comment":{"url":"https://api.github.com/repos/kubernetes/kubernetes/issues/comments/382799431","html_url":"https://github.com/kubernetes/kubernetes/issues/61999#issuecomment-382799431","issue_url":"https://api.github.com/repos/kubernetes/kubernetes/issues/61999","id":382799431,"user":{"login":"maxx-bachurin","id":3284114,"avatar_url":"https://avatars0.githubusercontent.com/u/3284114?v=4","gravatar_id":"","url":"https://api.github.com/users/maxx-bachurin","html_url":"https://github.com/maxx-bachurin","followers_url":"https://api.github.com/users/maxx-bachurin/followers","following_url":"https://api.github.com/users/maxx-bachurin/following{/other_user}","gists_url":"https://api.github.com/users/maxx-bachurin/gists{/gist_id}","starred_url":"https://api.github.com/users/maxx-bachurin/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/maxx-bachurin/subscriptions","organizations_url":"https://api.github.com/users/maxx-bachurin/orgs","repos_url":"https://api.github.com/users/maxx-bachurin/repos","events_url":"https://api.github.com/users/maxx-bachurin/events{/privacy}","received_events_url":"https://api.github.com/users/maxx-bachurin/received_events","type":"User","site_admin":false},"created_at":"2018-04-19T16:31:17Z","updated_at":"2018-04-19T16:31:17Z","author_association":"NONE","body":"It's likely that du burns all Burst Balance for the gp2 ebs volume. You can check it in AWS CloudWatch. \r\nIt seems du -s /var/lib/docker/overlay/ consumes a lot of IOPs during the check which burns Burst Balance for the gp2 ebs volume and makes it work at baseline performance. \r\n\r\nYou can use a simple check to find out iops consumption for du: \r\n\r\n\\time -f 'iops=%w' du /var/lib/docker/overlay/f8fb07fef9498184c4b2dfd7db4270dfadbe15d3bf59727ac23d4e6363f4595f > /dev/null\r\n\r\nIn my case the result is:\r\niops=5421\r\n\r\ndon't forget to drop fs cache before second run to get correct iops figures:\r\n\r\nsudo echo 3 >/proc/sys/vm/drop_caches\r\n"}}
{"actor":{"display_login":"maxx-bachurin"}}