{"action":"created","issue":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/30660","repository_url":"https://api.github.com/repos/cockroachdb/cockroach","labels_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/30660/labels{/name}","comments_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/30660/comments","events_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/30660/events","html_url":"https://github.com/cockroachdb/cockroach/issues/30660","id":363870477,"node_id":"MDU6SXNzdWUzNjM4NzA0Nzc=","number":30660,"title":"sql: TestCommandsWhileTableBeingDropped failed under stress","user":{"login":"cockroach-teamcity","id":20559710,"node_id":"MDQ6VXNlcjIwNTU5NzEw","avatar_url":"https://avatars0.githubusercontent.com/u/20559710?v=4","gravatar_id":"","url":"https://api.github.com/users/cockroach-teamcity","html_url":"https://github.com/cockroach-teamcity","followers_url":"https://api.github.com/users/cockroach-teamcity/followers","following_url":"https://api.github.com/users/cockroach-teamcity/following{/other_user}","gists_url":"https://api.github.com/users/cockroach-teamcity/gists{/gist_id}","starred_url":"https://api.github.com/users/cockroach-teamcity/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/cockroach-teamcity/subscriptions","organizations_url":"https://api.github.com/users/cockroach-teamcity/orgs","repos_url":"https://api.github.com/users/cockroach-teamcity/repos","events_url":"https://api.github.com/users/cockroach-teamcity/events{/privacy}","received_events_url":"https://api.github.com/users/cockroach-teamcity/received_events","type":"User","site_admin":false},"labels":[{"id":912737912,"node_id":"MDU6TGFiZWw5MTI3Mzc5MTI=","url":"https://api.github.com/repos/cockroachdb/cockroach/labels/A-core-kv","name":"A-core-kv","color":"c2e0c6","default":false},{"id":191587409,"node_id":"MDU6TGFiZWwxOTE1ODc0MDk=","url":"https://api.github.com/repos/cockroachdb/cockroach/labels/C-test-failure","name":"C-test-failure","color":"c5def5","default":false},{"id":335217860,"node_id":"MDU6TGFiZWwzMzUyMTc4NjA=","url":"https://api.github.com/repos/cockroachdb/cockroach/labels/O-robot","name":"O-robot","color":"666ad1","default":false}],"state":"open","locked":false,"assignee":{"login":"petermattis","id":6201335,"node_id":"MDQ6VXNlcjYyMDEzMzU=","avatar_url":"https://avatars0.githubusercontent.com/u/6201335?v=4","gravatar_id":"","url":"https://api.github.com/users/petermattis","html_url":"https://github.com/petermattis","followers_url":"https://api.github.com/users/petermattis/followers","following_url":"https://api.github.com/users/petermattis/following{/other_user}","gists_url":"https://api.github.com/users/petermattis/gists{/gist_id}","starred_url":"https://api.github.com/users/petermattis/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/petermattis/subscriptions","organizations_url":"https://api.github.com/users/petermattis/orgs","repos_url":"https://api.github.com/users/petermattis/repos","events_url":"https://api.github.com/users/petermattis/events{/privacy}","received_events_url":"https://api.github.com/users/petermattis/received_events","type":"User","site_admin":false},"assignees":[{"login":"petermattis","id":6201335,"node_id":"MDQ6VXNlcjYyMDEzMzU=","avatar_url":"https://avatars0.githubusercontent.com/u/6201335?v=4","gravatar_id":"","url":"https://api.github.com/users/petermattis","html_url":"https://github.com/petermattis","followers_url":"https://api.github.com/users/petermattis/followers","following_url":"https://api.github.com/users/petermattis/following{/other_user}","gists_url":"https://api.github.com/users/petermattis/gists{/gist_id}","starred_url":"https://api.github.com/users/petermattis/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/petermattis/subscriptions","organizations_url":"https://api.github.com/users/petermattis/orgs","repos_url":"https://api.github.com/users/petermattis/repos","events_url":"https://api.github.com/users/petermattis/events{/privacy}","received_events_url":"https://api.github.com/users/petermattis/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/cockroachdb/cockroach/milestones/13","html_url":"https://github.com/cockroachdb/cockroach/milestone/13","labels_url":"https://api.github.com/repos/cockroachdb/cockroach/milestones/13/labels","id":2745639,"node_id":"MDk6TWlsZXN0b25lMjc0NTYzOQ==","number":13,"title":"2.1","description":"","creator":{"login":"knz","id":642886,"node_id":"MDQ6VXNlcjY0Mjg4Ng==","avatar_url":"https://avatars3.githubusercontent.com/u/642886?v=4","gravatar_id":"","url":"https://api.github.com/users/knz","html_url":"https://github.com/knz","followers_url":"https://api.github.com/users/knz/followers","following_url":"https://api.github.com/users/knz/following{/other_user}","gists_url":"https://api.github.com/users/knz/gists{/gist_id}","starred_url":"https://api.github.com/users/knz/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/knz/subscriptions","organizations_url":"https://api.github.com/users/knz/orgs","repos_url":"https://api.github.com/users/knz/repos","events_url":"https://api.github.com/users/knz/events{/privacy}","received_events_url":"https://api.github.com/users/knz/received_events","type":"User","site_admin":false},"open_issues":394,"closed_issues":1736,"state":"open","created_at":"2017-09-05T15:30:49Z","updated_at":"2018-09-28T17:23:56Z","due_on":null,"closed_at":null},"comments":10,"created_at":"2018-09-26T06:03:39Z","updated_at":"2018-09-28T17:29:39Z","closed_at":null,"author_association":"MEMBER","body":"SHA: https://github.com/cockroachdb/cockroach/commits/c7b6cb20b36696d65853c3e16c0aec44d1e6fb2a\n\nParameters:\n```\nTAGS=\nGOFLAGS=\n```\n\nTo repro, try:\n\n```\n# Don't forget to check out a clean suitable branch and experiment with the\n# stress invocation until the desired results present themselves. For example,\n# using stressrace instead of stress and passing the '-p' stressflag which\n# controls concurrency.\n./scripts/gceworker.sh start && ./scripts/gceworker.sh mosh\ncd ~/go/src/github.com/cockroachdb/cockroach && \\\nmake stress TESTS=TestCommandsWhileTableBeingDropped PKG=github.com/cockroachdb/cockroach/pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-stderr=false -maxtime 20m -timeout 10m'\n```\n\nFailed test: https://teamcity.cockroachdb.com/viewLog.html?buildId=926394&tab=buildLog\n\n```\n\nI180926 06:00:57.365559 74038 storage/split_queue.go:116  [n1,split,s1,r6/1:/{System/tse-Table/System…}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.365589 74038 storage/split_queue.go:116  [n1,split,s1,r13/1:/{Table/16-Max}] shouldQueue: shouldQ=true priority=1.0\nI180926 06:00:57.365618 74038 storage/split_queue.go:116  [n1,split,s1,r5/1:/System/ts{d-e}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.365645 74038 storage/split_queue.go:116  [n1,split,s1,r2/1:/System/{-NodeLive…}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.365680 74038 storage/split_queue.go:116  [n1,split,s1,r1/1:/{Min-System/}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.365713 74038 storage/split_queue.go:116  [n1,split,s1,r11/1:/Table/1{4-5}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.369842 74240 sql/event_log.go:126  [n1,intExec=create-default-db] Event: \"create_database\", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}\nI180926 06:00:57.372018 73843 server/server.go:1605  [n1] done ensuring all necessary migrations have run\nI180926 06:00:57.372039 73843 server/server.go:1608  [n1] serving sql connections\nI180926 06:00:57.388306 74038 storage/split_queue.go:116  [n1,split,s1,r14/1:/{Table/17-Max}] shouldQueue: shouldQ=true priority=1.0\nI180926 06:00:57.388706 74038 storage/split_queue.go:116  [n1,split,s1,r9/1:/Table/1{2-3}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388785 74038 storage/split_queue.go:116  [n1,split,s1,r7/1:/Table/{SystemCon…-11}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388806 74038 storage/split_queue.go:116  [n1,split,s1,r10/1:/Table/1{3-4}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388835 74038 storage/split_queue.go:116  [n1,split,s1,r8/1:/Table/1{1-2}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388855 74038 storage/split_queue.go:116  [n1,split,s1,r12/1:/Table/1{5-6}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388872 74038 storage/split_queue.go:116  [n1,split,s1,r3/1:/System/NodeLiveness{-Max}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388905 74038 storage/split_queue.go:116  [n1,split,s1,r9/1:/Table/1{2-3}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388920 74038 storage/split_queue.go:116  [n1,split,s1,r4/1:/System/{NodeLive…-tsd}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388942 74038 storage/split_queue.go:116  [n1,split,s1,r1/1:/{Min-System/}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388962 74038 storage/split_queue.go:116  [n1,split,s1,r11/1:/Table/1{4-5}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388980 74038 storage/split_queue.go:116  [n1,split,s1,r8/1:/Table/1{1-2}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.388999 74038 storage/split_queue.go:116  [n1,split,s1,r10/1:/Table/1{3-4}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389017 74038 storage/split_queue.go:116  [n1,split,s1,r7/1:/Table/{SystemCon…-11}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389034 74038 storage/split_queue.go:116  [n1,split,s1,r6/1:/{System/tse-Table/System…}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389065 74038 storage/split_queue.go:116  [n1,split,s1,r5/1:/System/ts{d-e}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389082 74038 storage/split_queue.go:116  [n1,split,s1,r3/1:/System/NodeLiveness{-Max}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389097 74038 storage/split_queue.go:116  [n1,split,s1,r2/1:/System/{-NodeLive…}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389313 74278 server/server_update.go:67  [n1] no need to upgrade, cluster already at the newest version\nI180926 06:00:57.389377 74028 storage/split_queue.go:116  [n1,split,s1,r13/1:/Table/1{6-7}] shouldQueue: shouldQ=false priority=0.0\nI180926 06:00:57.389394 74028 storage/split_queue.go:116  [n1,split,s1,r14/1:/{Table/17-Max}] shouldQueue: shouldQ=true priority=1.0\n```"},"comment":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/comments/425509308","html_url":"https://github.com/cockroachdb/cockroach/issues/30660#issuecomment-425509308","issue_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/30660","id":425509308,"node_id":"MDEyOklzc3VlQ29tbWVudDQyNTUwOTMwOA==","user":{"login":"petermattis","id":6201335,"node_id":"MDQ6VXNlcjYyMDEzMzU=","avatar_url":"https://avatars0.githubusercontent.com/u/6201335?v=4","gravatar_id":"","url":"https://api.github.com/users/petermattis","html_url":"https://github.com/petermattis","followers_url":"https://api.github.com/users/petermattis/followers","following_url":"https://api.github.com/users/petermattis/following{/other_user}","gists_url":"https://api.github.com/users/petermattis/gists{/gist_id}","starred_url":"https://api.github.com/users/petermattis/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/petermattis/subscriptions","organizations_url":"https://api.github.com/users/petermattis/orgs","repos_url":"https://api.github.com/users/petermattis/repos","events_url":"https://api.github.com/users/petermattis/events{/privacy}","received_events_url":"https://api.github.com/users/petermattis/received_events","type":"User","site_admin":false},"created_at":"2018-09-28T17:29:39Z","updated_at":"2018-09-28T17:29:39Z","author_association":"CONTRIBUTOR","body":"Note that this recent failure does show a similar pattern to the previous one. The server is splitting away and then it splits `r12` creating `r13`. `r13` is then queued:\r\n\r\n```\r\nI180928 16:00:36.901429 266 storage/split_queue.go:116  [n1,split,s1,r13/1:/{Table/16-Max}] shouldQueue: shouldQ=true priority=1.0\r\nI180928 16:00:36.901459 266 storage/queue.go:522  [n1,split,s1,r13/1:/{Table/16-Max}] adding: priority=1.000\r\nI180928 16:00:36.901476 266 storage/queue.go:540  [n1,split,s1,r13/1:/{Table/16-Max}] add: qlen=1 signalled=false\r\n...\r\nI180928 16:00:36.902177 215 storage/split_queue.go:116  [n1,split,s1,r13/1:/{Table/16-Max}] shouldQueue: shouldQ=true priority=1.0\r\n...\r\nI180928 16:00:36.903351 266 storage/split_queue.go:116  [n1,split,s1,r13/1:/{Table/16-Max}] shouldQueue: shouldQ=true priority=1.0\r\n...\r\nI180928 16:00:46.684142 286 storage/split_queue.go:116  [n1,split,s1,r13/1:/{Table/16-Max}] shouldQueue: shouldQ=true priority=1.0\r\nI180928 16:00:46.684166 286 storage/queue.go:522  [n1,split,s1,r13/1:/{Table/16-Max}] adding: priority=1.000\r\nI180928 16:00:46.684190 286 storage/queue.go:540  [n1,split,s1,r13/1:/{Table/16-Max}] add: qlen=1 signalled=false\r\n...\r\nI180928 16:00:46.685938 537 storage/queue.go:715  [n1,split,s1,r13/1:/{Table/16-Max}] processing replica\r\nI180928 16:00:46.685954 537 storage/queue.go:753  [n1,split,s1,r13/1:/{Table/16-Max}] processing\r\n```\r\n\r\nIt is only after the the enqueuing at `16:00:46.684166` that `r13` is processed. Ignore the `signalled=`  part of the log message. That was broken instrumentation. It very much looks like `r13` is getting queued but not processed for some reason. "}}
{"actor":{"display_login":"petermattis"}}