{"action":"created","issue":{"url":"https://api.github.com/repos/grafana/metrictank/issues/947","repository_url":"https://api.github.com/repos/grafana/metrictank","labels_url":"https://api.github.com/repos/grafana/metrictank/issues/947/labels{/name}","comments_url":"https://api.github.com/repos/grafana/metrictank/issues/947/comments","events_url":"https://api.github.com/repos/grafana/metrictank/issues/947/events","html_url":"https://github.com/grafana/metrictank/issues/947","id":334237436,"node_id":"MDU6SXNzdWUzMzQyMzc0MzY=","number":947,"title":"sometimes pod doesn't become ready. I think because of problem with .State attribute","user":{"login":"Dieterbe","id":20774,"node_id":"MDQ6VXNlcjIwNzc0","avatar_url":"https://avatars2.githubusercontent.com/u/20774?v=4","gravatar_id":"","url":"https://api.github.com/users/Dieterbe","html_url":"https://github.com/Dieterbe","followers_url":"https://api.github.com/users/Dieterbe/followers","following_url":"https://api.github.com/users/Dieterbe/following{/other_user}","gists_url":"https://api.github.com/users/Dieterbe/gists{/gist_id}","starred_url":"https://api.github.com/users/Dieterbe/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Dieterbe/subscriptions","organizations_url":"https://api.github.com/users/Dieterbe/orgs","repos_url":"https://api.github.com/users/Dieterbe/repos","events_url":"https://api.github.com/users/Dieterbe/events{/privacy}","received_events_url":"https://api.github.com/users/Dieterbe/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2018-06-20T20:29:10Z","updated_at":"2018-06-22T03:45:51Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"sometimes metrictank pods that use the kafka-mdm plugin remain not ready because they return 503 on /, despite having all of their backlog replayed\r\n\r\n```\r\n2018/06/20 19:53:15 [DEBUG] memberlist: Initiating push/pull sync with: 172.22.128.7:7946\r\n[Macaron] 2018-06-20 19:53:18: Started GET / for 172.19.64.0\r\n[Macaron] 2018-06-20 19:53:18: Completed / 503 Service Unavailable in 867.431µs\r\n[Macaron] 2018-06-20 19:53:18: Started GET /node for 172.19.64.0\r\n[Macaron] 2018-06-20 19:53:18: Completed /node 200 OK in 906.048µs\r\n[Macaron] 2018-06-20 19:53:28: Started GET / for 172.19.64.0\r\n[Macaron] 2018-06-20 19:53:28: Started GET /node for 172.19.64.0\r\n[Macaron] 2018-06-20 19:53:28: Completed / 503 Service Unavailable in 809.084µs\r\n[Macaron] 2018-06-20 19:53:28: Completed /node 200 OK in 854.825µs\r\n```\r\n\r\nhowever their priority is good.\r\n`metrictank.stats.$environment.$instance.cluster.self.priority.gauge32` is at 0\r\nand : \r\n\r\n```\r\ncurl http://localhost:6060/priority | jsonpp\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   490  100   490    0     0    703      0 --:--:-- --:--:-- --:--:--   702\r\n[\r\n    {\r\n        \"Title\": \"kafka-mdm:\",\r\n        \"Explanation\": {\r\n            \"Explanation\": {\r\n                \"Status\": {\r\n                    \"120\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1907,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"121\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1910,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"122\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1870,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"123\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1911,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"124\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1923,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"125\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 1950,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"126\": {\r\n                        \"Lag\": 1,\r\n                        \"Rate\": 2278,\r\n                        \"Priority\": 0\r\n                    },\r\n                    \"127\": {\r\n                        \"Lag\": 2,\r\n                        \"Rate\": 2249,\r\n                        \"Priority\": 0\r\n                    }\r\n                },\r\n                \"Priority\": 0,\r\n                \"Updated\": \"2018-06-20T19:59:35.159761495Z\"\r\n            },\r\n            \"Now\": \"2018-06-20T19:59:40.430106864Z\"\r\n        }\r\n    }\r\n]\r\n```\r\n```\r\ncurl http://localhost:6060/node | jsonpp\r\n  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current\r\n                                 Dload  Upload   Total   Spent    Left  Speed\r\n100   436  100   436    0     0    698      0 --:--:-- --:--:-- --:--:--   697\r\n{\r\n    \"name\": \"mt-read15-75291-large-ttd-b-553865555-b44b3\",\r\n    \"version\": \"0.9.0-99-g0847450\",\r\n    \"primary\": false,\r\n    \"primaryChange\": \"2018-06-20T16:04:10.804909693Z\",\r\n    \"state\": \"NodeNotReady\",\r\n    \"priority\": 0,\r\n    \"started\": \"2018-06-20T16:04:10.803162723Z\",\r\n    \"stateChange\": \"2018-06-20T16:04:10.804909929Z\",\r\n    \"partitions\": [\r\n        120,\r\n        121,\r\n        122,\r\n        123,\r\n        124,\r\n        125,\r\n        126,\r\n        127\r\n    ],\r\n    \"apiPort\": 6060,\r\n    \"apiScheme\": \"http\",\r\n    \"updated\": \"2018-06-20T16:43:25.157847604Z\",\r\n    \"remoteAddr\": \"172.19.64.38\"\r\n}\r\n```\r\n\r\n\r\n\r\n```\r\ncurl -v http://localhost:6060/\r\n*   Trying ::1...\r\n* TCP_NODELAY set\r\n* Connected to localhost (::1) port 6060 (#0)\r\n> GET / HTTP/1.1\r\n> Host: localhost:6060\r\n> User-Agent: curl/7.60.0\r\n> Accept: */*\r\n> \r\n< HTTP/1.1 503 Service Unavailable\r\n< Content-Type: text/plain\r\n< Trace-Id: 6327f0bdd793cb50\r\n< Vary: Origin\r\n< Date: Wed, 20 Jun 2018 20:03:29 GMT\r\n< Content-Length: 14\r\n< \r\n* Connection #0 to host localhost left intact\r\n```\r\n\r\ncurl doesn't show the body, but:\r\n```\r\nsudo ngrep -W byline -d any port 6060\r\ninterface: any\r\nfilter: ( port 6060 ) and (ip || ip6)\r\n####\r\nT ::1:45294 -> ::1:6060 [AP] #4\r\nGET / HTTP/1.1.\r\nUser-Agent: Wget/1.19.5 (linux-gnu).\r\nAccept: */*.\r\nAccept-Encoding: identity.\r\nHost: localhost:6060.\r\nConnection: Keep-Alive.\r\n.\r\n\r\n##\r\nT ::1:6060 -> ::1:45294 [AP] #6\r\nHTTP/1.1 503 Service Unavailable.\r\nContent-Type: text/plain.\r\nTrace-Id: 88f036c9e9fc5a6.\r\nVary: Origin.\r\nDate: Wed, 20 Jun 2018 20:13:55 GMT.\r\nContent-Length: 14.\r\n.\r\nnode not ready <---------------------------------------------------------\r\n```\r\nso that confirms we trigger the 503 in appStatus: \r\n\r\n```\r\nfunc (s *Server) appStatus(ctx *middleware.Context) {\r\n\tif cluster.Manager.IsReady() {\r\n\t\tctx.PlainText(200, []byte(\"OK\"))\r\n\t\treturn\r\n\t}\r\n\r\n\tresponse.Write(ctx, response.NewError(http.StatusServiceUnavailable, \"node not ready\"))\r\n}\r\n```\r\n\r\nwhich means this returns false:\r\n```\r\nfunc (n HTTPNode) IsReady() bool {\r\n        return n.State == NodeReady && n.Priority <= maxPrio\r\n}\r\n```\r\n\r\nas we can see above in the above `curl http://localhost:6060/node` output, the problem is.State\r\n\r\nhowever, `metrictank.stats.$environment.$instance.cluster.self.state.ready.gauge1` becomes 1 shortly after startup.\r\nand from looking at the code, that metric (`nodeReady`) should always be in sync with the .State property on the node. \r\nthe one exception i can see is in MemberlistManager.NotifyUpdate(), an update may come in for a node and we'll update the state of that node, but if that node has the same name our nodeName, then that way we could set state to something else without updating the `nodeReady` metric.\r\n"},"comment":{"url":"https://api.github.com/repos/grafana/metrictank/issues/comments/399312144","html_url":"https://github.com/grafana/metrictank/issues/947#issuecomment-399312144","issue_url":"https://api.github.com/repos/grafana/metrictank/issues/947","id":399312144,"node_id":"MDEyOklzc3VlQ29tbWVudDM5OTMxMjE0NA==","user":{"login":"woodsaj","id":8415072,"node_id":"MDQ6VXNlcjg0MTUwNzI=","avatar_url":"https://avatars3.githubusercontent.com/u/8415072?v=4","gravatar_id":"","url":"https://api.github.com/users/woodsaj","html_url":"https://github.com/woodsaj","followers_url":"https://api.github.com/users/woodsaj/followers","following_url":"https://api.github.com/users/woodsaj/following{/other_user}","gists_url":"https://api.github.com/users/woodsaj/gists{/gist_id}","starred_url":"https://api.github.com/users/woodsaj/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/woodsaj/subscriptions","organizations_url":"https://api.github.com/users/woodsaj/orgs","repos_url":"https://api.github.com/users/woodsaj/repos","events_url":"https://api.github.com/users/woodsaj/events{/privacy}","received_events_url":"https://api.github.com/users/woodsaj/received_events","type":"User","site_admin":false},"created_at":"2018-06-22T03:45:51Z","updated_at":"2018-06-22T03:45:51Z","author_association":"MEMBER","body":"a race condition seems like the most likely issue.  We can solve this easily enough by using the \"StateChange\" timestamp to drop updates that are older than the state we already have."}}
{"actor":{"display_login":"woodsaj"}}