{"action":"created","issue":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/28395","repository_url":"https://api.github.com/repos/cockroachdb/cockroach","labels_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/28395/labels{/name}","comments_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/28395/comments","events_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/28395/events","html_url":"https://github.com/cockroachdb/cockroach/issues/28395","id":348894435,"node_id":"MDU6SXNzdWUzNDg4OTQ0MzU=","number":28395,"title":"storage: long time waiting for replication in TestCluster","user":{"login":"andreimatei","id":377201,"node_id":"MDQ6VXNlcjM3NzIwMQ==","avatar_url":"https://avatars1.githubusercontent.com/u/377201?v=4","gravatar_id":"","url":"https://api.github.com/users/andreimatei","html_url":"https://github.com/andreimatei","followers_url":"https://api.github.com/users/andreimatei/followers","following_url":"https://api.github.com/users/andreimatei/following{/other_user}","gists_url":"https://api.github.com/users/andreimatei/gists{/gist_id}","starred_url":"https://api.github.com/users/andreimatei/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/andreimatei/subscriptions","organizations_url":"https://api.github.com/users/andreimatei/orgs","repos_url":"https://api.github.com/users/andreimatei/repos","events_url":"https://api.github.com/users/andreimatei/events{/privacy}","received_events_url":"https://api.github.com/users/andreimatei/received_events","type":"User","site_admin":false},"labels":[{"id":912733225,"node_id":"MDU6TGFiZWw5MTI3MzMyMjU=","url":"https://api.github.com/repos/cockroachdb/cockroach/labels/A-core-distribution","name":"A-core-distribution","color":"c2e0c6","default":false},{"id":78928345,"node_id":"MDU6TGFiZWw3ODkyODM0NQ==","url":"https://api.github.com/repos/cockroachdb/cockroach/labels/C-bug","name":"C-bug","color":"c5def5","default":false}],"state":"open","locked":false,"assignee":{"login":"andreimatei","id":377201,"node_id":"MDQ6VXNlcjM3NzIwMQ==","avatar_url":"https://avatars1.githubusercontent.com/u/377201?v=4","gravatar_id":"","url":"https://api.github.com/users/andreimatei","html_url":"https://github.com/andreimatei","followers_url":"https://api.github.com/users/andreimatei/followers","following_url":"https://api.github.com/users/andreimatei/following{/other_user}","gists_url":"https://api.github.com/users/andreimatei/gists{/gist_id}","starred_url":"https://api.github.com/users/andreimatei/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/andreimatei/subscriptions","organizations_url":"https://api.github.com/users/andreimatei/orgs","repos_url":"https://api.github.com/users/andreimatei/repos","events_url":"https://api.github.com/users/andreimatei/events{/privacy}","received_events_url":"https://api.github.com/users/andreimatei/received_events","type":"User","site_admin":false},"assignees":[{"login":"andreimatei","id":377201,"node_id":"MDQ6VXNlcjM3NzIwMQ==","avatar_url":"https://avatars1.githubusercontent.com/u/377201?v=4","gravatar_id":"","url":"https://api.github.com/users/andreimatei","html_url":"https://github.com/andreimatei","followers_url":"https://api.github.com/users/andreimatei/followers","following_url":"https://api.github.com/users/andreimatei/following{/other_user}","gists_url":"https://api.github.com/users/andreimatei/gists{/gist_id}","starred_url":"https://api.github.com/users/andreimatei/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/andreimatei/subscriptions","organizations_url":"https://api.github.com/users/andreimatei/orgs","repos_url":"https://api.github.com/users/andreimatei/repos","events_url":"https://api.github.com/users/andreimatei/events{/privacy}","received_events_url":"https://api.github.com/users/andreimatei/received_events","type":"User","site_admin":false}],"milestone":null,"comments":0,"created_at":"2018-08-08T21:13:53Z","updated_at":"2018-08-09T21:30:53Z","closed_at":null,"author_association":"MEMBER","body":"I can make `TestCluster.WaitForFullReplication` replication take over 20s. Here's a dummy test that reproduces it in about a minute with:\r\n```\r\nmake stress PKG='./pkg/ccl/backupccl' TESTS=TestXXX TESTTIMEOUT=20s STRESSFLAGS='-p 1'\r\n```\r\nI don't know what's going on but it doesn't sound good.\r\nI've began looking at this because I've noticed individual ccl tests sometimes taking a long time.\r\n\r\n\r\n```\r\n+func TestXXX(t *testing.T) {\r\n+       defer leaktest.AfterTest(t)()\r\n+\r\n+       dir, dirCleanupFn := testutils.TempDir(t)\r\n+       var params base.TestClusterArgs\r\n+       params.ServerArgs.ExternalIODir = dir\r\n+       params.ServerArgs.UseDatabase = \"data\"\r\n+\r\n+       tc := testcluster.StartTestCluster(t, multiNode, params)\r\n+       cleanup := func() {\r\n+               tempDirs := []string{dir}\r\n+               for _, s := range tc.Servers {\r\n+                       for _, e := range s.Engines() {\r\n+                               tempDirs = append(tempDirs, e.GetAuxiliaryDir())\r\n+                       }\r\n+               }\r\n+               tc.Stopper().Stop(context.TODO()) // cleans up in memory storage's auxiliary dirs\r\n+               dirCleanupFn()                    // cleans up dir, which is the nodelocal:// storage\r\n+\r\n+               for _, temp := range tempDirs {\r\n+                       testutils.SucceedsSoon(t, func() error {\r\n+                               items, err := ioutil.ReadDir(temp)\r\n+                               if err != nil && !os.IsNotExist(err) {\r\n+                                       t.Fatal(err)\r\n+                               }\r\n+                               for _, leftover := range items {\r\n+                                       return errors.Errorf(\"found %q remaining in %s\", leftover.Name(), temp)\r\n+                               }\r\n+                               return nil\r\n+                       })\r\n+               }\r\n+       }\r\n+       cleanup()\r\n+}\r\n```\r\n\r\ncc @tschottdorf so he's aware, and @benesch cause he likes to look at test failures"},"comment":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/comments/411904039","html_url":"https://github.com/cockroachdb/cockroach/issues/28395#issuecomment-411904039","issue_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/28395","id":411904039,"node_id":"MDEyOklzc3VlQ29tbWVudDQxMTkwNDAzOQ==","user":{"login":"andreimatei","id":377201,"node_id":"MDQ6VXNlcjM3NzIwMQ==","avatar_url":"https://avatars1.githubusercontent.com/u/377201?v=4","gravatar_id":"","url":"https://api.github.com/users/andreimatei","html_url":"https://github.com/andreimatei","followers_url":"https://api.github.com/users/andreimatei/followers","following_url":"https://api.github.com/users/andreimatei/following{/other_user}","gists_url":"https://api.github.com/users/andreimatei/gists{/gist_id}","starred_url":"https://api.github.com/users/andreimatei/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/andreimatei/subscriptions","organizations_url":"https://api.github.com/users/andreimatei/orgs","repos_url":"https://api.github.com/users/andreimatei/repos","events_url":"https://api.github.com/users/andreimatei/events{/privacy}","received_events_url":"https://api.github.com/users/andreimatei/received_events","type":"User","site_admin":false},"created_at":"2018-08-09T21:30:53Z","updated_at":"2018-08-09T21:30:53Z","author_association":"MEMBER","body":"Done some digging and learned some things.\r\nIt would appear that the story is that sometimes, soon after the `TestCluster` is started, the replication queue gets the following error for (all?) ranges:\r\n```\r\n[replicate,n1,s1,r9/1:/Table/1{2-3}] range requires a replication change, but lacks a quorum of live replicas (0/1)\r\n```\r\nThe 0/1 seems to mean that (someone thinks that) the node that has the replica is not alive. This seems funky but I hear can be a result of gossip delay; I don't know what it means exactly.\r\nAfter this error, the range is neither put in purgatory, nor re-enqueued. So, it needs to wait for the scanner to come around to it again. And the scanner gets back to it much later. This \"much later\" has been introduced in #27441 (cc @spencerkimball) which changed the scanner policy, slowing it down at least for cluster with few ranges.\r\n\r\nNow what to do about it? I guess that even if we understand and fix that bizarre `0/1` error, upreplication in the cluster's beginning could probably still fail because the other nodes are not necessarily alive yet.\r\nAn idea is for the `TestCluster` to get a hook for manually triggering a full scan when all nodes are known to be alive. There already exists an `Store.ForceReplicationScanAndProcess()`. Or maybe we just switch the `TestCluster's` timings; @petermattis presciently suggested that maybe the `TestCluster` needs another policy in #27697.\r\n\r\nMy heart hopes that that PR is also the cause of our recent-ish `had <x> ranges at startup, expected 22` flakiness plague (e.g. #28320, #28323) - maybe there's split failures combined with split queue slowness. In fact, I vaguely remember @knz lamenting about one of these failures a while ago and saying that he suspects one of Spencer's change - was it #27441 that you suspected, Rafa?\r\nOn a tangent, maybe the split failures always existed or maybe they've been exacerbated by the scenario covered in #28270.\r\n\r\ncc @alex @bdarnell \r\n\r\n"}}
{"actor":{"display_login":"andreimatei"}}