{"action":"created","issue":{"url":"https://api.github.com/repos/coreos/etcd/issues/5870","repository_url":"https://api.github.com/repos/coreos/etcd","labels_url":"https://api.github.com/repos/coreos/etcd/issues/5870/labels{/name}","comments_url":"https://api.github.com/repos/coreos/etcd/issues/5870/comments","events_url":"https://api.github.com/repos/coreos/etcd/issues/5870/events","html_url":"https://github.com/coreos/etcd/issues/5870","id":163823976,"number":5870,"title":"etcdserver: failed to send out heartbeat on time","user":{"login":"maverick-racheal","id":19584960,"avatar_url":"https://avatars.githubusercontent.com/u/19584960?v=3","gravatar_id":"","url":"https://api.github.com/users/maverick-racheal","html_url":"https://github.com/maverick-racheal","followers_url":"https://api.github.com/users/maverick-racheal/followers","following_url":"https://api.github.com/users/maverick-racheal/following{/other_user}","gists_url":"https://api.github.com/users/maverick-racheal/gists{/gist_id}","starred_url":"https://api.github.com/users/maverick-racheal/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/maverick-racheal/subscriptions","organizations_url":"https://api.github.com/users/maverick-racheal/orgs","repos_url":"https://api.github.com/users/maverick-racheal/repos","events_url":"https://api.github.com/users/maverick-racheal/events{/privacy}","received_events_url":"https://api.github.com/users/maverick-racheal/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/coreos/etcd/labels/kind/question","name":"kind/question","color":"c7def8"}],"state":"open","locked":false,"assignee":{"login":"xiang90","id":4479947,"avatar_url":"https://avatars.githubusercontent.com/u/4479947?v=3","gravatar_id":"","url":"https://api.github.com/users/xiang90","html_url":"https://github.com/xiang90","followers_url":"https://api.github.com/users/xiang90/followers","following_url":"https://api.github.com/users/xiang90/following{/other_user}","gists_url":"https://api.github.com/users/xiang90/gists{/gist_id}","starred_url":"https://api.github.com/users/xiang90/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/xiang90/subscriptions","organizations_url":"https://api.github.com/users/xiang90/orgs","repos_url":"https://api.github.com/users/xiang90/repos","events_url":"https://api.github.com/users/xiang90/events{/privacy}","received_events_url":"https://api.github.com/users/xiang90/received_events","type":"User","site_admin":false},"assignees":[{"login":"xiang90","id":4479947,"avatar_url":"https://avatars.githubusercontent.com/u/4479947?v=3","gravatar_id":"","url":"https://api.github.com/users/xiang90","html_url":"https://github.com/xiang90","followers_url":"https://api.github.com/users/xiang90/followers","following_url":"https://api.github.com/users/xiang90/following{/other_user}","gists_url":"https://api.github.com/users/xiang90/gists{/gist_id}","starred_url":"https://api.github.com/users/xiang90/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/xiang90/subscriptions","organizations_url":"https://api.github.com/users/xiang90/orgs","repos_url":"https://api.github.com/users/xiang90/repos","events_url":"https://api.github.com/users/xiang90/events{/privacy}","received_events_url":"https://api.github.com/users/xiang90/received_events","type":"User","site_admin":false}],"milestone":null,"comments":8,"created_at":"2016-07-05T10:56:21Z","updated_at":"2016-07-08T03:44:15Z","closed_at":null,"body":"We brought up a cluster with three members and once the setup is stable we see the below logs\r\n\r\n{\"log\":\"2016-07-05 10:45:16.964197 W | etcdserver: failed to send out heartbeat on time (deadline exceeded for 1.85087351s)\\n\",\"stream\":\"stderr\",\"time\":\"2016-07-05T10:45:16.964317922Z\"}\r\n{\"log\":\"2016-07-05 10:45:16.964292 W | etcdserver: server is likely overloaded\\n\",\"stream\":\"stderr\",\"time\":\"2016-07-05T10:45:16.964427649Z\"}\r\n\r\nI changed the heartbeat timer and the election timer based on the RTT time in my setup.\r\n\r\nping 10.18.3.148\r\nPING 10.18.3.148 (10.18.3.148) 56(84) bytes of data.\r\n64 bytes from 10.18.3.148: icmp_seq=1 ttl=64 time=0.554 ms\r\n64 bytes from 10.18.3.148: icmp_seq=2 ttl=64 time=0.413 ms\r\n64 bytes from 10.18.3.148: icmp_seq=3 ttl=64 time=0.396 ms\r\n\r\nping 10.18.3.151\r\nPING 10.18.3.151 (10.18.3.151) 56(84) bytes of data.\r\n64 bytes from 10.18.3.151: icmp_seq=1 ttl=64 time=0.466 ms\r\n64 bytes from 10.18.3.151: icmp_seq=2 ttl=64 time=0.459 ms\r\n64 bytes from 10.18.3.151: icmp_seq=3 ttl=64 time=0.526 ms\r\n\r\n{\"log\":\"2016-07-05 10:20:37.003826 I | etcdserver: heartbeat = 1000ms\\n\",\"stream\":\"stderr\",\"time\":\"2016-07-05T10:20:37.003939995Z\"}\r\n{\"log\":\"2016-07-05 10:20:37.003906 I | etcdserver: election = 5000ms\\n\",\"stream\":\"stderr\",\"time\":\"2016-07-05T10:20:37.004101906Z\"}\r\n\r\nStats on followers\r\ncurl http://127.0.0.1:4001/v2/stats/self | python -mjson.tool\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   350  100   350    0     0   119k      0 --:--:-- --:--:-- --:--:--  170k\r\n{\r\n    \"id\": \"d1496d0a12cd5f72\",\r\n    \"leaderInfo\": {\r\n        \"leader\": \"23d0b9d58779cdab\",\r\n        \"startTime\": \"2016-07-05T10:21:19.556075327Z\",\r\n        \"uptime\": \"32m43.572036434s\"\r\n    },\r\n    \"name\": \"etc150\",\r\n    \"recvAppendRequestCnt\": 11273,\r\n    \"recvBandwidthRate\": 2398.514253044226,\r\n    \"recvPkgRate\": 5.476935247743307,\r\n    \"sendAppendRequestCnt\": 0,\r\n    \"startTime\": \"2016-07-05T10:20:36.701918706Z\",\r\n    \"state\": \"StateFollower\"\r\n}\r\n\r\n\r\nLeader\r\ncurl http://127.0.0.1:4001/v2/stats/leader | python -mjson.tool\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   440  100   440    0     0   141k      0 --:--:-- --:--:-- --:--:--  214k\r\n{\r\n    \"followers\": {\r\n        \"65a2890a61e31a80\": {\r\n            \"counts\": {\r\n                \"fail\": 0,\r\n                \"success\": 11173\r\n            },\r\n            \"latency\": {\r\n                \"average\": 0.008557420656940854,\r\n                \"current\": 0.001534,\r\n                \"maximum\": 1.391827,\r\n                \"minimum\": 0.000549,\r\n                \"standardDeviation\": 0.024860923502788825\r\n            }\r\n        },\r\n        \"d1496d0a12cd5f72\": {\r\n            \"counts\": {\r\n                \"fail\": 0,\r\n                \"success\": 11231\r\n            },\r\n            \"latency\": {\r\n                \"average\": 0.0077906355622828745,\r\n                \"current\": 0.001608,\r\n                \"maximum\": 0.585447,\r\n                \"minimum\": 0.000603,\r\n                \"standardDeviation\": 0.017981316123206685\r\n            }\r\n        }\r\n    },\r\n    \"leader\": \"23d0b9d58779cdab\"\r\n}\r\n\r\ncurl http://127.0.0.1:4001/v2/stats/self | python -mjson.tool\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   352  100   352    0     0   173k      0 --:--:-- --:--:-- --:--:--  343k\r\n{\r\n    \"id\": \"23d0b9d58779cdab\",\r\n    \"leaderInfo\": {\r\n        \"leader\": \"23d0b9d58779cdab\",\r\n        \"startTime\": \"2016-07-05T10:21:19.930360147Z\",\r\n        \"uptime\": \"33m36.131574527s\"\r\n    },\r\n    \"name\": \"etc151\",\r\n    \"recvAppendRequestCnt\": 165,\r\n    \"sendAppendRequestCnt\": 22686,\r\n    \"sendBandwidthRate\": 3932.7020115961404,\r\n    \"sendPkgRate\": 10.999180555164079,\r\n    \"startTime\": \"2016-07-05T10:20:37.059879681Z\",\r\n    \"state\": \"StateLeader\"\r\n}\r\n\r\nFollower 2\r\ncurl http://127.0.0.1:4001/v2/stats/self | python -mjson.tool\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   353  100   353    0     0   310k      0 --:--:-- --:--:-- --:--:--  344k\r\n{\r\n    \"id\": \"65a2890a61e31a80\",\r\n    \"leaderInfo\": {\r\n        \"leader\": \"23d0b9d58779cdab\",\r\n        \"startTime\": \"2016-07-05T10:21:19.805540361Z\",\r\n        \"uptime\": \"33m59.848322369s\"\r\n    },\r\n    \"name\": \"etc148\",\r\n    \"recvAppendRequestCnt\": 11425,\r\n    \"recvBandwidthRate\": 2012.7089388921465,\r\n    \"recvPkgRate\": 5.061954249442668,\r\n    \"sendAppendRequestCnt\": 335,\r\n    \"startTime\": \"2016-07-05T10:20:36.883783373Z\",\r\n    \"state\": \"StateFollower\"\r\n}\r\n\r\n\r\nHowever these errors are still seen.\r\nThe cluster state is mostly healthy even though there are few instances when it oscillates to unhealthy\r\n\r\nsudo docker -H unix:///var/run/docker-bootstrap.sock exec cda5e65ec3b7 ./etcdctl cluster-health\r\nmember 23d0b9d58779cdab is healthy: got healthy result from http://10.18.3.151:4001\r\nmember 65a2890a61e31a80 is healthy: got healthy result from http://10.18.3.148:4001\r\nmember d1496d0a12cd5f72 is healthy: got healthy result from http://10.18.3.150:4001\r\ncluster is healthy\r\nAlso there are no packet drops between these nodes.\r\n\r\nCouple of doubts/questions.\r\n1) What is the optimum configuration to avoid any heartbeat  miss. The setup is fairly simple with a K8 master and around 15 pods created on 3 different nodes including the master. ETCD running on all the three nodes in clustered mode.\r\n2) Why does cluster health oscillate to unhealthy. \r\n\r\netcdctl version 2.3.7\r\n"},"comment":{"url":"https://api.github.com/repos/coreos/etcd/issues/comments/231268359","html_url":"https://github.com/coreos/etcd/issues/5870#issuecomment-231268359","issue_url":"https://api.github.com/repos/coreos/etcd/issues/5870","id":231268359,"user":{"login":"xiang90","id":4479947,"avatar_url":"https://avatars.githubusercontent.com/u/4479947?v=3","gravatar_id":"","url":"https://api.github.com/users/xiang90","html_url":"https://github.com/xiang90","followers_url":"https://api.github.com/users/xiang90/followers","following_url":"https://api.github.com/users/xiang90/following{/other_user}","gists_url":"https://api.github.com/users/xiang90/gists{/gist_id}","starred_url":"https://api.github.com/users/xiang90/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/xiang90/subscriptions","organizations_url":"https://api.github.com/users/xiang90/orgs","repos_url":"https://api.github.com/users/xiang90/repos","events_url":"https://api.github.com/users/xiang90/events{/privacy}","received_events_url":"https://api.github.com/users/xiang90/received_events","type":"User","site_admin":false},"created_at":"2016-07-08T03:44:15Z","updated_at":"2016-07-08T03:44:15Z","body":"@xloggerster Your disk io was slow. Some of them took longer than 50ms. That is why etcd complaints. Try to get a better disk (not shared by 3 etcd or use SSD) or make the heartbeat interval longer."}}
{"actor":{"display_login":"xiang90"}}