{"action":"created","issue":{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/4141","labels_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/4141/labels{/name}","comments_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/4141/comments","events_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/4141/events","html_url":"https://github.com/GoogleCloudPlatform/kubernetes/issues/4141","id":56611294,"number":4141,"title":"bug: kubelet etcd watch errors","user":{"login":"sym3tri","id":224222,"avatar_url":"https://avatars.githubusercontent.com/u/224222?v=3","gravatar_id":"","url":"https://api.github.com/users/sym3tri","html_url":"https://github.com/sym3tri","followers_url":"https://api.github.com/users/sym3tri/followers","following_url":"https://api.github.com/users/sym3tri/following{/other_user}","gists_url":"https://api.github.com/users/sym3tri/gists{/gist_id}","starred_url":"https://api.github.com/users/sym3tri/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sym3tri/subscriptions","organizations_url":"https://api.github.com/users/sym3tri/orgs","repos_url":"https://api.github.com/users/sym3tri/repos","events_url":"https://api.github.com/users/sym3tri/events{/privacy}","received_events_url":"https://api.github.com/users/sym3tri/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/labels/priority/P2","name":"priority/P2","color":"fbca04"},{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/labels/team/node","name":"team/node","color":"d2b48c"}],"state":"open","locked":false,"assignee":{"login":"erictune","id":8105590,"avatar_url":"https://avatars.githubusercontent.com/u/8105590?v=3","gravatar_id":"","url":"https://api.github.com/users/erictune","html_url":"https://github.com/erictune","followers_url":"https://api.github.com/users/erictune/followers","following_url":"https://api.github.com/users/erictune/following{/other_user}","gists_url":"https://api.github.com/users/erictune/gists{/gist_id}","starred_url":"https://api.github.com/users/erictune/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/erictune/subscriptions","organizations_url":"https://api.github.com/users/erictune/orgs","repos_url":"https://api.github.com/users/erictune/repos","events_url":"https://api.github.com/users/erictune/events{/privacy}","received_events_url":"https://api.github.com/users/erictune/received_events","type":"User","site_admin":false},"milestone":null,"comments":3,"created_at":"2015-02-05T00:46:23Z","updated_at":"2015-03-12T00:16:31Z","closed_at":null,"body":"I spun up a k8s cluster on CoreOS using [https://github.com/pires/kubernetes-vagrant-coreos-cluster](this vagrant setup). I was able to create & list Pods, but the Pod containers would never get launched. The kubelet log showed what looks like an issue with an etcd watcher. Note the 'key modified index' is much lower than the cluster index (cluster: 26286, key: 19255), meaning the watch will never get triggered. I understand this is a known issue in etcd, and it cannot be fixed correctly without major changes to the data model. To work around this, the kubernetes watchers need to be using the cluster index when creating watchers rather than the key's modified index.\r\n\r\nManual Workaround: \"touch\" the etcd key by doing:\r\n```\r\netcdctl get /registry/nodes/172.17.8.102/boundpods | etcdctl set /registry/nodes/172.17.8.102/boundpods\r\n```\r\n\r\nkubelet logs:\r\n\r\n```\r\nFeb 04 22:02:03 node-01 kubelet[17799]: I0204 22:02:03.039952   17799 etcd.go:78] Watch closed (&api.Status{TypeMeta:api.TypeMeta{Kind:\"\", APIVersion:\"\"}, ListMeta:api.ListMeta{SelfLink:\"\", ResourceVersion:\"\"}, Status:\"Failure\", Message:\"401: The event in requested index is outdated and cleared (the requested history has been cleared [26284/19255]) [27283]\", Reason:\"\", Details:(*api.StatusDetails)(nil), Code:0}). Reopening.\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.040393   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.040452   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.040462   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false | method GET\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.041716   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.041748   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.048829   17799 logs.go:40] etcd DEBUG: watch /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.050031   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.050793   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.051116   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255 | method GET\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.053068   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.053375   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:04 node-01 kubelet[17799]: I0204 22:02:04.053659   17799 etcd.go:78] Watch closed (&api.Status{TypeMeta:api.TypeMeta{Kind:\"\", APIVersion:\"\"}, ListMeta:api.ListMeta{SelfLink:\"\", ResourceVersion:\"\"}, Status:\"Failure\", Message:\"401: The event in requested index is outdated and cleared (the requested history has been cleared [26285/19255]) [27284]\", Reason:\"\", Details:(*api.StatusDetails)(nil), Code:0}). Reopening.\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.054636   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.054718   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.054748   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false | method GET\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.056090   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.056133   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.059809   17799 logs.go:40] etcd DEBUG: watch /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.061249   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.061287   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.061297   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255 | method GET\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.063736   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.063769   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:05 node-01 kubelet[17799]: I0204 22:02:05.063830   17799 etcd.go:78] Watch closed (&api.Status{TypeMeta:api.TypeMeta{Kind:\"\", APIVersion:\"\"}, ListMeta:api.ListMeta{SelfLink:\"\", ResourceVersion:\"\"}, Status:\"Failure\", Message:\"401: The event in requested index is outdated and cleared (the requested history has been cleared [26285/19255]) [27284]\", Reason:\"\", Details:(*api.StatusDetails)(nil), Code:0}). Reopening.\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.067255   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.067314   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.067324   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false | method GET\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.068758   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.068792   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&recursive=false&sorted=false\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.073435   17799 logs.go:40] etcd DEBUG: watch /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.073674   17799 logs.go:40] etcd DEBUG: get /registry/nodes/172.17.8.102/boundpods [http://172.17.8.101:4001]\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.074112   17799 logs.go:40] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.075787   17799 logs.go:40] etcd DEBUG: send.request.to http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255 | method GET\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.076988   17799 logs.go:40] etcd DEBUG: recv.response.fromhttp://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.077013   17799 logs.go:40] etcd DEBUG: recv.success.http://172.17.8.101:4001/v2/keys/registry/nodes/172.17.8.102/boundpods?consistent=true&wait=true&waitIndex=19255\r\nFeb 04 22:02:06 node-01 kubelet[17799]: I0204 22:02:06.077064   17799 etcd.go:78] Watch closed (&api.Status{TypeMeta:api.TypeMeta{Kind:\"\", APIVersion:\"\"}, ListMeta:api.ListMeta{SelfLink:\"\", ResourceVersion:\"\"}, Status:\"Failure\", Message:\"401: The event in requested index is outdated and cleared (the requested history has been cleared [26286/19255]) [27285]\", Reason:\"\", Details:(*api.StatusDetails)(nil), Code:0}). Reopening.\r\n```"},"comment":{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/comments/78401167","html_url":"https://github.com/GoogleCloudPlatform/kubernetes/issues/4141#issuecomment-78401167","issue_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/4141","id":78401167,"user":{"login":"pires","id":1752631,"avatar_url":"https://avatars.githubusercontent.com/u/1752631?v=3","gravatar_id":"","url":"https://api.github.com/users/pires","html_url":"https://github.com/pires","followers_url":"https://api.github.com/users/pires/followers","following_url":"https://api.github.com/users/pires/following{/other_user}","gists_url":"https://api.github.com/users/pires/gists{/gist_id}","starred_url":"https://api.github.com/users/pires/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/pires/subscriptions","organizations_url":"https://api.github.com/users/pires/orgs","repos_url":"https://api.github.com/users/pires/repos","events_url":"https://api.github.com/users/pires/events{/privacy}","received_events_url":"https://api.github.com/users/pires/received_events","type":"User","site_admin":false},"created_at":"2015-03-12T00:16:31Z","updated_at":"2015-03-12T00:16:31Z","body":"This has been fixed recently with #4708, right?"}}