{"action":"created","comment":{"url":"https://api.github.com/repos/youtube/vitess/pulls/comments/168047993","pull_request_review_id":96353032,"id":168047993,"diff_hunk":"@@ -207,53 +244,94 @@ func (server *ResilientServer) GetSrvKeyspaceNames(ctx context.Context, cell str\n \t}\n \tserver.mutex.Unlock()\n \n-\t// Lock the entry, and do everything holding the lock.  This\n-\t// means two concurrent requests will only issue one\n-\t// underlying query.\n+\t// Lock the entry, and do everything holding the lock except\n+\t// querying the underlying topo server.\n+\t//\n+\t// This means that unless the topo server is very slow, two concurrent\n+\t// requests will only issue one underlying query.\n \tentry.mutex.Lock()\n \tdefer entry.mutex.Unlock()\n \n-\t// If it is not time to check again, then return either the cached\n-\t// value or the cached error\n \tcacheValid := entry.value != nil && time.Since(entry.insertionTime) < server.cacheTTL\n \tshouldRefresh := time.Since(entry.lastQueryTime) > server.cacheRefresh\n \n+\t// If it is not time to check again, then return either the cached\n+\t// value or the cached error but don't ask consul again.\n \tif !shouldRefresh {\n \t\tif cacheValid {\n \t\t\treturn entry.value, nil\n \t\t}\n \t\treturn nil, entry.lastError\n \t}\n \n-\t// Not in cache or needs refresh so try to get the real value.\n-\t// We use the context that issued the query here.\n-\tresult, err := server.topoServer.GetSrvKeyspaceNames(ctx, cell)\n-\tif err == nil {\n-\t\t// save the value we got and the current time in the cache\n-\t\tentry.insertionTime = time.Now()\n-\t\tentry.value = result\n-\t} else {\n-\t\tif entry.insertionTime.IsZero() {\n-\t\t\tserver.counts.Add(errorCategory, 1)\n-\t\t\tlog.Errorf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (no cached value, caching and returning error)\", ctx, cell, err)\n-\n-\t\t} else if cacheValid {\n-\t\t\tserver.counts.Add(cachedCategory, 1)\n-\t\t\tlog.Warningf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (returning cached value: %v %v)\", ctx, cell, err, entry.value, entry.lastError)\n-\t\t\tresult = entry.value\n-\t\t\terr = nil\n-\t\t} else {\n-\t\t\tserver.counts.Add(errorCategory, 1)\n-\t\t\tlog.Errorf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (cached value expired)\", ctx, cell, err)\n-\t\t\tentry.insertionTime = time.Time{}\n-\t\t\tentry.value = nil\n-\t\t}\n+\t// Rrefresh the state in a background goroutine if no refresh is already\n+\t// in progress none is already running. This way queries are not blocked\n+\t// while the cache is still valid but past the refresh time, and avoids\n+\t// calling out to the topo service while the lock is held.\n+\tif entry.refreshingChan == nil {\n+\t\tentry.refreshingChan = make(chan bool)\n+\t\tentry.lastQueryTime = time.Now()\n+\t\tgo func() {\n+\t\t\tresult, err := server.topoServer.GetSrvKeyspaceNames(ctx, cell)\n+\n+\t\t\tentry.mutex.Lock()\n+\t\t\tdefer func() {\n+\t\t\t\tclose(entry.refreshingChan)\n+\t\t\t\tentry.refreshingChan = nil\n+\t\t\t\tentry.mutex.Unlock()\n+\t\t\t}()\n+\n+\t\t\tif err == nil {\n+\t\t\t\t// save the value we got and the current time in the cache\n+\t\t\t\tentry.insertionTime = time.Now()\n+\t\t\t\tentry.value = result\n+\t\t\t} else {\n+\t\t\t\tserver.counts.Add(errorCategory, 1)\n+\t\t\t\tif entry.insertionTime.IsZero() {\n+\t\t\t\t\tlog.Errorf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (no cached value, caching and returning error)\", ctx, cell, err)\n+\n+\t\t\t\t} else if entry.value != nil && time.Since(entry.insertionTime) < server.cacheTTL {\n+\t\t\t\t\tserver.counts.Add(cachedCategory, 1)\n+\t\t\t\t\tlog.Warningf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (keeping cached value: %v)\", ctx, cell, err, entry.value)\n+\t\t\t\t} else {\n+\t\t\t\t\tlog.Errorf(\"GetSrvKeyspaceNames(%v, %v) failed: %v (cached value expired)\", ctx, cell, err)\n+\t\t\t\t\tentry.insertionTime = time.Time{}\n+\t\t\t\t\tentry.value = nil\n+\t\t\t\t}\n+\t\t\t}\n+\n+\t\t\tentry.lastError = err\n+\t\t\tentry.lastErrorCtx = ctx\n+\t\t}()\n+\t}\n+\n+\t// If the cached entry is still valid then use it, otherwise wait\n+\t// for the refresh attempt to complete to get a more up to date\n+\t// response.\n+\t//\n+\t// In the event that the topo service is slow or unresponsive either\n+\t// on the initial fetch or if the cache TTL expires, then several\n+\t// requests could be blocked on refreshingCond waiting for the response\n+\t// to come back.\n+\tif cacheValid {\n+\t\treturn entry.value, nil\n+\t}\n+\n+\trefreshingChan := entry.refreshingChan\n+\tentry.mutex.Unlock()\n+\tselect {\n+\tcase _, _ = <-refreshingChan:","path":"go/vt/srvtopo/resilient_server.go","position":245,"original_position":245,"commit_id":"13cfb4e776cc3691b9b5d7ad5b94bb4fffc27317","original_commit_id":"13cfb4e776cc3691b9b5d7ad5b94bb4fffc27317","user":{"login":"alainjobart","id":4625714,"avatar_url":"https://avatars3.githubusercontent.com/u/4625714?v=4","gravatar_id":"","url":"https://api.github.com/users/alainjobart","html_url":"https://github.com/alainjobart","followers_url":"https://api.github.com/users/alainjobart/followers","following_url":"https://api.github.com/users/alainjobart/following{/other_user}","gists_url":"https://api.github.com/users/alainjobart/gists{/gist_id}","starred_url":"https://api.github.com/users/alainjobart/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/alainjobart/subscriptions","organizations_url":"https://api.github.com/users/alainjobart/orgs","repos_url":"https://api.github.com/users/alainjobart/repos","events_url":"https://api.github.com/users/alainjobart/events{/privacy}","received_events_url":"https://api.github.com/users/alainjobart/received_events","type":"User","site_admin":false},"body":"this can just be:\r\ncase <-refreshingChan:\r\n(same as next line)","created_at":"2018-02-14T00:37:12Z","updated_at":"2018-02-14T00:47:30Z","html_url":"https://github.com/youtube/vitess/pull/3641#discussion_r168047993","pull_request_url":"https://api.github.com/repos/youtube/vitess/pulls/3641","author_association":"OWNER","_links":{"self":{"href":"https://api.github.com/repos/youtube/vitess/pulls/comments/168047993"},"html":{"href":"https://github.com/youtube/vitess/pull/3641#discussion_r168047993"},"pull_request":{"href":"https://api.github.com/repos/youtube/vitess/pulls/3641"}}},"pull_request":{"url":"https://api.github.com/repos/youtube/vitess/pulls/3641","id":168021911,"html_url":"https://github.com/youtube/vitess/pull/3641","diff_url":"https://github.com/youtube/vitess/pull/3641.diff","patch_url":"https://github.com/youtube/vitess/pull/3641.patch","issue_url":"https://api.github.com/repos/youtube/vitess/issues/3641","number":3641,"state":"open","locked":false,"title":"make the resilient topo cache even more resilient and informative","user":{"login":"demmer","id":3308504,"avatar_url":"https://avatars3.githubusercontent.com/u/3308504?v=4","gravatar_id":"","url":"https://api.github.com/users/demmer","html_url":"https://github.com/demmer","followers_url":"https://api.github.com/users/demmer/followers","following_url":"https://api.github.com/users/demmer/following{/other_user}","gists_url":"https://api.github.com/users/demmer/gists{/gist_id}","starred_url":"https://api.github.com/users/demmer/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/demmer/subscriptions","organizations_url":"https://api.github.com/users/demmer/orgs","repos_url":"https://api.github.com/users/demmer/repos","events_url":"https://api.github.com/users/demmer/events{/privacy}","received_events_url":"https://api.github.com/users/demmer/received_events","type":"User","site_admin":false},"body":"# Overview\r\nImprove the status UI for the resilient topo cache, make GetSrvKeyspaceNames fetch asynchronously, and fix a logic bug in the watch-based caching for GetSrvKeyspace.\r\n\r\nThis incorporates the ideas first proposed by @yangxuanjia in #3640 while addressing my concerns about the refresh interval and properly managing locks and state.\r\n\r\n# Details\r\nThis first came up because I wanted better indication in the status UI about the state of the cache. In particular, it used to either show the cached value _or_ show the most recent error, but would not indicate if the cache was valid or not.\r\n\r\nTo address this, I changed the status UI to display the current cached value (if any), the last error (if any), as well as information about the cache freshness / TTL.\r\n\r\nNext, as discussed in slack and in #3640 I moved the topo in GetSrvKeyspaceNames into a separate goroutine, and kept tracking state in the entry to make sure only one topo request is outstanding. This makes sure that a cached value can always be returned immediately even if the topo service is unresponsive or slow.\r\n\r\nHowever, unlike in the other proposal, if there is no cached value, all requests block waiting for the fetcher goroutine to complete. This seems like an acceptable tradeoff to me since it avoids errors on the initial query, and for the most part should insulate callers from topo service unavailability or slowness.\r\n\r\nFinally, I noticed a logic bug in the earlier changes that I made to cache the watched SrvKeyspace object. Previously the lastValueTime was updated on every change, but that meant that if the watch failed after some time where no changes were detected, the cache did not properly keep the last value for the full TTL as designed. To address this, I changed it to update lastValueTime whenever an established watch returns, either due to error or the value being in the cache.\r\n\r\n# Testing\r\nI added a unit test for the last case and did a decent amount of manual testing both using zookeeper and consul. \r\n\r\nI'd like to add some tests for the logic in the status UI since that turned out to be surprisingly tricky to get right, as well as the case where the topo service is blocked.\r\n","created_at":"2018-02-08T16:31:00Z","updated_at":"2018-02-14T00:47:31Z","closed_at":null,"merged_at":null,"merge_commit_sha":"3d11ff16fe0dd19678f923429c0cd734b7cf0e8e","assignee":null,"assignees":[],"requested_reviewers":[],"requested_teams":[],"labels":[{"id":318803109,"url":"https://api.github.com/repos/youtube/vitess/labels/cla:%20yes","name":"cla: yes","color":"009800","default":false}],"milestone":null,"commits_url":"https://api.github.com/repos/youtube/vitess/pulls/3641/commits","review_comments_url":"https://api.github.com/repos/youtube/vitess/pulls/3641/comments","review_comment_url":"https://api.github.com/repos/youtube/vitess/pulls/comments{/number}","comments_url":"https://api.github.com/repos/youtube/vitess/issues/3641/comments","statuses_url":"https://api.github.com/repos/youtube/vitess/statuses/13cfb4e776cc3691b9b5d7ad5b94bb4fffc27317","head":{"label":"tinyspeck:resilient-topo-more-resilient-and-informative","ref":"resilient-topo-more-resilient-and-informative","sha":"13cfb4e776cc3691b9b5d7ad5b94bb4fffc27317","user":{"login":"tinyspeck","id":371467,"avatar_url":"https://avatars1.githubusercontent.com/u/371467?v=4","gravatar_id":"","url":"https://api.github.com/users/tinyspeck","html_url":"https://github.com/tinyspeck","followers_url":"https://api.github.com/users/tinyspeck/followers","following_url":"https://api.github.com/users/tinyspeck/following{/other_user}","gists_url":"https://api.github.com/users/tinyspeck/gists{/gist_id}","starred_url":"https://api.github.com/users/tinyspeck/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/tinyspeck/subscriptions","organizations_url":"https://api.github.com/users/tinyspeck/orgs","repos_url":"https://api.github.com/users/tinyspeck/repos","events_url":"https://api.github.com/users/tinyspeck/events{/privacy}","received_events_url":"https://api.github.com/users/tinyspeck/received_events","type":"Organization","site_admin":false},"repo":{"id":79269846,"name":"vitess","full_name":"tinyspeck/vitess","owner":{"login":"tinyspeck","id":371467,"avatar_url":"https://avatars1.githubusercontent.com/u/371467?v=4","gravatar_id":"","url":"https://api.github.com/users/tinyspeck","html_url":"https://github.com/tinyspeck","followers_url":"https://api.github.com/users/tinyspeck/followers","following_url":"https://api.github.com/users/tinyspeck/following{/other_user}","gists_url":"https://api.github.com/users/tinyspeck/gists{/gist_id}","starred_url":"https://api.github.com/users/tinyspeck/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/tinyspeck/subscriptions","organizations_url":"https://api.github.com/users/tinyspeck/orgs","repos_url":"https://api.github.com/users/tinyspeck/repos","events_url":"https://api.github.com/users/tinyspeck/events{/privacy}","received_events_url":"https://api.github.com/users/tinyspeck/received_events","type":"Organization","site_admin":false},"private":false,"html_url":"https://github.com/tinyspeck/vitess","description":"Vitess is a database clustering system for horizontal scaling of MySQL.","fork":true,"url":"https://api.github.com/repos/tinyspeck/vitess","forks_url":"https://api.github.com/repos/tinyspeck/vitess/forks","keys_url":"https://api.github.com/repos/tinyspeck/vitess/keys{/key_id}","collaborators_url":"https://api.github.com/repos/tinyspeck/vitess/collaborators{/collaborator}","teams_url":"https://api.github.com/repos/tinyspeck/vitess/teams","hooks_url":"https://api.github.com/repos/tinyspeck/vitess/hooks","issue_events_url":"https://api.github.com/repos/tinyspeck/vitess/issues/events{/number}","events_url":"https://api.github.com/repos/tinyspeck/vitess/events","assignees_url":"https://api.github.com/repos/tinyspeck/vitess/assignees{/user}","branches_url":"https://api.github.com/repos/tinyspeck/vitess/branches{/branch}","tags_url":"https://api.github.com/repos/tinyspeck/vitess/tags","blobs_url":"https://api.github.com/repos/tinyspeck/vitess/git/blobs{/sha}","git_tags_url":"https://api.github.com/repos/tinyspeck/vitess/git/tags{/sha}","git_refs_url":"https://api.github.com/repos/tinyspeck/vitess/git/refs{/sha}","trees_url":"https://api.github.com/repos/tinyspeck/vitess/git/trees{/sha}","statuses_url":"https://api.github.com/repos/tinyspeck/vitess/statuses/{sha}","languages_url":"https://api.github.com/repos/tinyspeck/vitess/languages","stargazers_url":"https://api.github.com/repos/tinyspeck/vitess/stargazers","contributors_url":"https://api.github.com/repos/tinyspeck/vitess/contributors","subscribers_url":"https://api.github.com/repos/tinyspeck/vitess/subscribers","subscription_url":"https://api.github.com/repos/tinyspeck/vitess/subscription","commits_url":"https://api.github.com/repos/tinyspeck/vitess/commits{/sha}","git_commits_url":"https://api.github.com/repos/tinyspeck/vitess/git/commits{/sha}","comments_url":"https://api.github.com/repos/tinyspeck/vitess/comments{/number}","issue_comment_url":"https://api.github.com/repos/tinyspeck/vitess/issues/comments{/number}","contents_url":"https://api.github.com/repos/tinyspeck/vitess/contents/{+path}","compare_url":"https://api.github.com/repos/tinyspeck/vitess/compare/{base}...{head}","merges_url":"https://api.github.com/repos/tinyspeck/vitess/merges","archive_url":"https://api.github.com/repos/tinyspeck/vitess/{archive_format}{/ref}","downloads_url":"https://api.github.com/repos/tinyspeck/vitess/downloads","issues_url":"https://api.github.com/repos/tinyspeck/vitess/issues{/number}","pulls_url":"https://api.github.com/repos/tinyspeck/vitess/pulls{/number}","milestones_url":"https://api.github.com/repos/tinyspeck/vitess/milestones{/number}","notifications_url":"https://api.github.com/repos/tinyspeck/vitess/notifications{?since,all,participating}","labels_url":"https://api.github.com/repos/tinyspeck/vitess/labels{/name}","releases_url":"https://api.github.com/repos/tinyspeck/vitess/releases{/id}","deployments_url":"https://api.github.com/repos/tinyspeck/vitess/deployments","created_at":"2017-01-17T20:41:49Z","updated_at":"2017-01-17T20:41:57Z","pushed_at":"2018-02-14T00:35:38Z","git_url":"git://github.com/tinyspeck/vitess.git","ssh_url":"git@github.com:tinyspeck/vitess.git","clone_url":"https://github.com/tinyspeck/vitess.git","svn_url":"https://github.com/tinyspeck/vitess","homepage":"http://vitess.io","size":93952,"stargazers_count":0,"watchers_count":0,"language":"Go","has_issues":false,"has_projects":true,"has_downloads":true,"has_wiki":false,"has_pages":false,"forks_count":0,"mirror_url":null,"archived":false,"open_issues_count":2,"license":{"key":"apache-2.0","name":"Apache License 2.0","spdx_id":"Apache-2.0","url":"https://api.github.com/licenses/apache-2.0"},"forks":0,"open_issues":2,"watchers":0,"default_branch":"master"}},"base":{"label":"youtube:master","ref":"master","sha":"c34b9859a4ab8cdd4624c5c14f7f56f2465492b9","user":{"login":"youtube","id":4052902,"avatar_url":"https://avatars0.githubusercontent.com/u/4052902?v=4","gravatar_id":"","url":"https://api.github.com/users/youtube","html_url":"https://github.com/youtube","followers_url":"https://api.github.com/users/youtube/followers","following_url":"https://api.github.com/users/youtube/following{/other_user}","gists_url":"https://api.github.com/users/youtube/gists{/gist_id}","starred_url":"https://api.github.com/users/youtube/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/youtube/subscriptions","organizations_url":"https://api.github.com/users/youtube/orgs","repos_url":"https://api.github.com/users/youtube/repos","events_url":"https://api.github.com/users/youtube/events{/privacy}","received_events_url":"https://api.github.com/users/youtube/received_events","type":"Organization","site_admin":false},"repo":{"id":11008207,"name":"vitess","full_name":"youtube/vitess","owner":{"login":"youtube","id":4052902,"avatar_url":"https://avatars0.githubusercontent.com/u/4052902?v=4","gravatar_id":"","url":"https://api.github.com/users/youtube","html_url":"https://github.com/youtube","followers_url":"https://api.github.com/users/youtube/followers","following_url":"https://api.github.com/users/youtube/following{/other_user}","gists_url":"https://api.github.com/users/youtube/gists{/gist_id}","starred_url":"https://api.github.com/users/youtube/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/youtube/subscriptions","organizations_url":"https://api.github.com/users/youtube/orgs","repos_url":"https://api.github.com/users/youtube/repos","events_url":"https://api.github.com/users/youtube/events{/privacy}","received_events_url":"https://api.github.com/users/youtube/received_events","type":"Organization","site_admin":false},"private":false,"html_url":"https://github.com/youtube/vitess","description":"Vitess is a database clustering system for horizontal scaling of MySQL.","fork":false,"url":"https://api.github.com/repos/youtube/vitess","forks_url":"https://api.github.com/repos/youtube/vitess/forks","keys_url":"https://api.github.com/repos/youtube/vitess/keys{/key_id}","collaborators_url":"https://api.github.com/repos/youtube/vitess/collaborators{/collaborator}","teams_url":"https://api.github.com/repos/youtube/vitess/teams","hooks_url":"https://api.github.com/repos/youtube/vitess/hooks","issue_events_url":"https://api.github.com/repos/youtube/vitess/issues/events{/number}","events_url":"https://api.github.com/repos/youtube/vitess/events","assignees_url":"https://api.github.com/repos/youtube/vitess/assignees{/user}","branches_url":"https://api.github.com/repos/youtube/vitess/branches{/branch}","tags_url":"https://api.github.com/repos/youtube/vitess/tags","blobs_url":"https://api.github.com/repos/youtube/vitess/git/blobs{/sha}","git_tags_url":"https://api.github.com/repos/youtube/vitess/git/tags{/sha}","git_refs_url":"https://api.github.com/repos/youtube/vitess/git/refs{/sha}","trees_url":"https://api.github.com/repos/youtube/vitess/git/trees{/sha}","statuses_url":"https://api.github.com/repos/youtube/vitess/statuses/{sha}","languages_url":"https://api.github.com/repos/youtube/vitess/languages","stargazers_url":"https://api.github.com/repos/youtube/vitess/stargazers","contributors_url":"https://api.github.com/repos/youtube/vitess/contributors","subscribers_url":"https://api.github.com/repos/youtube/vitess/subscribers","subscription_url":"https://api.github.com/repos/youtube/vitess/subscription","commits_url":"https://api.github.com/repos/youtube/vitess/commits{/sha}","git_commits_url":"https://api.github.com/repos/youtube/vitess/git/commits{/sha}","comments_url":"https://api.github.com/repos/youtube/vitess/comments{/number}","issue_comment_url":"https://api.github.com/repos/youtube/vitess/issues/comments{/number}","contents_url":"https://api.github.com/repos/youtube/vitess/contents/{+path}","compare_url":"https://api.github.com/repos/youtube/vitess/compare/{base}...{head}","merges_url":"https://api.github.com/repos/youtube/vitess/merges","archive_url":"https://api.github.com/repos/youtube/vitess/{archive_format}{/ref}","downloads_url":"https://api.github.com/repos/youtube/vitess/downloads","issues_url":"https://api.github.com/repos/youtube/vitess/issues{/number}","pulls_url":"https://api.github.com/repos/youtube/vitess/pulls{/number}","milestones_url":"https://api.github.com/repos/youtube/vitess/milestones{/number}","notifications_url":"https://api.github.com/repos/youtube/vitess/notifications{?since,all,participating}","labels_url":"https://api.github.com/repos/youtube/vitess/labels{/name}","releases_url":"https://api.github.com/repos/youtube/vitess/releases{/id}","deployments_url":"https://api.github.com/repos/youtube/vitess/deployments","created_at":"2013-06-27T21:20:28Z","updated_at":"2018-02-13T22:53:30Z","pushed_at":"2018-02-14T00:35:39Z","git_url":"git://github.com/youtube/vitess.git","ssh_url":"git@github.com:youtube/vitess.git","clone_url":"https://github.com/youtube/vitess.git","svn_url":"https://github.com/youtube/vitess","homepage":"http://vitess.io","size":94146,"stargazers_count":5532,"watchers_count":5532,"language":"Go","has_issues":true,"has_projects":true,"has_downloads":true,"has_wiki":false,"has_pages":true,"forks_count":727,"mirror_url":null,"archived":false,"open_issues_count":164,"license":{"key":"apache-2.0","name":"Apache License 2.0","spdx_id":"Apache-2.0","url":"https://api.github.com/licenses/apache-2.0"},"forks":727,"open_issues":164,"watchers":5532,"default_branch":"master"}},"_links":{"self":{"href":"https://api.github.com/repos/youtube/vitess/pulls/3641"},"html":{"href":"https://github.com/youtube/vitess/pull/3641"},"issue":{"href":"https://api.github.com/repos/youtube/vitess/issues/3641"},"comments":{"href":"https://api.github.com/repos/youtube/vitess/issues/3641/comments"},"review_comments":{"href":"https://api.github.com/repos/youtube/vitess/pulls/3641/comments"},"review_comment":{"href":"https://api.github.com/repos/youtube/vitess/pulls/comments{/number}"},"commits":{"href":"https://api.github.com/repos/youtube/vitess/pulls/3641/commits"},"statuses":{"href":"https://api.github.com/repos/youtube/vitess/statuses/13cfb4e776cc3691b9b5d7ad5b94bb4fffc27317"}},"author_association":"COLLABORATOR"}}
{"actor":{"display_login":"alainjobart"}}