{"action":"created","issue":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/10427","repository_url":"https://api.github.com/repos/cockroachdb/cockroach","labels_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/10427/labels{/name}","comments_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/10427/comments","events_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/10427/events","html_url":"https://github.com/cockroachdb/cockroach/issues/10427","id":186980189,"number":10427,"title":"stability: OOM on delta","user":{"login":"bdarnell","id":160562,"avatar_url":"https://avatars.githubusercontent.com/u/160562?v=3","gravatar_id":"","url":"https://api.github.com/users/bdarnell","html_url":"https://github.com/bdarnell","followers_url":"https://api.github.com/users/bdarnell/followers","following_url":"https://api.github.com/users/bdarnell/following{/other_user}","gists_url":"https://api.github.com/users/bdarnell/gists{/gist_id}","starred_url":"https://api.github.com/users/bdarnell/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bdarnell/subscriptions","organizations_url":"https://api.github.com/users/bdarnell/orgs","repos_url":"https://api.github.com/users/bdarnell/repos","events_url":"https://api.github.com/users/bdarnell/events{/privacy}","received_events_url":"https://api.github.com/users/bdarnell/received_events","type":"User","site_admin":false},"labels":[{"id":371606733,"url":"https://api.github.com/repos/cockroachdb/cockroach/labels/stability","name":"stability","color":"b60205","default":false}],"state":"open","locked":false,"assignee":{"login":"bdarnell","id":160562,"avatar_url":"https://avatars.githubusercontent.com/u/160562?v=3","gravatar_id":"","url":"https://api.github.com/users/bdarnell","html_url":"https://github.com/bdarnell","followers_url":"https://api.github.com/users/bdarnell/followers","following_url":"https://api.github.com/users/bdarnell/following{/other_user}","gists_url":"https://api.github.com/users/bdarnell/gists{/gist_id}","starred_url":"https://api.github.com/users/bdarnell/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bdarnell/subscriptions","organizations_url":"https://api.github.com/users/bdarnell/orgs","repos_url":"https://api.github.com/users/bdarnell/repos","events_url":"https://api.github.com/users/bdarnell/events{/privacy}","received_events_url":"https://api.github.com/users/bdarnell/received_events","type":"User","site_admin":false},"assignees":[{"login":"bdarnell","id":160562,"avatar_url":"https://avatars.githubusercontent.com/u/160562?v=3","gravatar_id":"","url":"https://api.github.com/users/bdarnell","html_url":"https://github.com/bdarnell","followers_url":"https://api.github.com/users/bdarnell/followers","following_url":"https://api.github.com/users/bdarnell/following{/other_user}","gists_url":"https://api.github.com/users/bdarnell/gists{/gist_id}","starred_url":"https://api.github.com/users/bdarnell/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bdarnell/subscriptions","organizations_url":"https://api.github.com/users/bdarnell/orgs","repos_url":"https://api.github.com/users/bdarnell/repos","events_url":"https://api.github.com/users/bdarnell/events{/privacy}","received_events_url":"https://api.github.com/users/bdarnell/received_events","type":"User","site_admin":false}],"milestone":null,"comments":51,"created_at":"2016-11-03T05:13:27Z","updated_at":"2016-11-21T22:11:22Z","closed_at":null,"body":"One node on delta (running 9ce883365) ran out of memory, with a large spike in goroutine count right before the end. This node had also experienced problems with the previous build (when prevote was enabled)\r\n\r\n![image](https://cloud.githubusercontent.com/assets/160562/19956018/4978051a-a1c2-11e6-9d3e-bbddf32e44cf.png)\r\n\r\nThe logs show a lot of intent resolutions being cancelled in the command queue:\r\n\r\n```\r\nW161103 01:21:41.071928 22449127 storage/replica.go:1240  [n8,s16,r2341/7:/Table/55\r\n/1/197{22994…-34433…}] context canceled while in command queue: ResolveIntent [/Tab\r\nle/55/1/1973297837063008645/\"986e18e6-d1fc-48b9-8153-27e0148c025d\"/5778676/0,/Min),\r\n Noop [/Min,/Min), Noop [/Min,/Min), Noop [/Min,/Min), Noop [/Min,/Min), Noop [/Min\r\n,/Min), Noop [/Min,/Min), Noop [/Min,/Min), Noop [/Min,/Min)\r\n```\r\n\r\nand `raftMu` being held for over a second at a time (across multiple ranges).\r\n\r\nThis node had also experienced problems under the previous build, which we had blamed on prevote. \r\n\r\nMany goroutines are blocked at replica.go:1221 (waiting for cmdQMu) for very long times. There are 10k+ of these but panicparse isn't grouping them all together for some reason):\r\n\r\n```\r\n1173: semacquire [15~264 minutes] [Created by grpc.(*Server).serveStreams.func1 @ server.go:423]\r\n    sync                sema.go:47                  runtime_Semacquire(#42751)\r\n    sync                mutex.go:85                 (*Mutex).Lock(#42750)\r\n    syncutil            timedmutex.go:84            (*TimedMutex).Lock(#32315)\r\n    storage             replica.go:1221             (*Replica).beginCmds(#32314, #254751, *, *, *, *, 0)\r\n    storage             replica.go:1628             (*Replica).tryAddWriteCmd(#32314, #254751, *, *, 0, #246, 0x7, 0x8ec, 0, 0, ...)\r\n    storage             replica.go:1603             (*Replica).addWriteCmd(#32314, #254751, *, *, 0, #246, 0x7, 0x8ec, 0, 0, ...)\r\n    storage             replica.go:1104             (*Replica).Send(#32314, #254751, *, *, 0, #246, 0x7, 0x8ec, 0, 0, ...)\r\n    storage             store.go:2333               (*Store).Send(#1687, #254751, *, *, 0, #246, 0x7, 0x8ec, 0, 0, ...)\r\n    storage             stores.go:187               (*Stores).Send(#804, #254751, *, 0, 0, #246, 0x7, 0x8ec, 0, 0, ...)\r\n    server              node.go:843                 (*Node).batchInternal.func1(0, 0)\r\n    stop                stopper.go:245              (*Stopper).RunTaskWithErr(#751, *, 0, 0)\r\n    server              node.go:854                 (*Node).batchInternal(#519, #254751, *, *, *, *, 0x603fa7)\r\n    server              node.go:874                 (*Node).Batch(#519, #254751, *, *, 0, 0xac1, 0xac1)\r\n    roachpb             api.pb.go:1512              _Internal_Batch_Handler(#41, #519, #254751, *, *, 0, 0, 0, 0, *)\r\n    grpc                server.go:611               (*Server).processUnaryRPC(#691, #110, *, *, #726, #75, 0, 0, 0)\r\n    grpc                server.go:769               (*Server).handleStream(#691, #110, *, *, 0)\r\n    grpc                server.go:422               (*Server).serveStreams.func1.1(*, #691, #110, *, *)\r\n```\r\n\r\nIt looks like the command queue has gotten large:\r\n\r\n```\r\n1: runnable [Created by grpc.(*Server).serveStreams.func1 @ server.go:423]\r\n    interval            interval.go:678             (*Node).doMatch(#54501, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34715)\r\n    interval            interval.go:692             (*Node).doMatch(#54500, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34714)\r\n    interval            interval.go:680             (*Node).doMatch(#54502, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34716)\r\n    interval            interval.go:680             (*Node).doMatch(#54503, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34717)\r\n    interval            interval.go:692             (*Node).doMatch(#54499, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34713)\r\n    interval            interval.go:692             (*Node).doMatch(#54498, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34712)\r\n    interval            interval.go:680             (*Node).doMatch(#54504, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34718)\r\n    interval            interval.go:692             (*Node).doMatch(#44087, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34711)\r\n    interval            interval.go:692             (*Node).doMatch(#76407, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34710)\r\n    interval            interval.go:692             (*Node).doMatch(#64129, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #4909)\r\n    interval            interval.go:692             (*Node).doMatch(#41627, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #28365)\r\n    interval            interval.go:680             (*Node).doMatch(#19169, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #34719)\r\n    interval            interval.go:692             (*Node).doMatch(#40511, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #35269)\r\n    interval            interval.go:680             (*Node).doMatch(#47831, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #30706)\r\n    interval            interval.go:680             (*Node).doMatch(#58539, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #13753)\r\n    interval            interval.go:692             (*Node).doMatch(#10407, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #58350)\r\n    interval            interval.go:680             (*Node).doMatch(#46061, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, #62, #9663)\r\n    interval            interval.go:673             (*Tree).DoMatching(#18943, #22866, #64177, 0, 0x1, #64177, 0x1, 0x1, 0x1)\r\n    storage             command_queue.go:338        (*CommandQueue).getOverlaps(#18943, #64177, 0, 0x1, #64177, 0x1, 0x1, #244168, 0x287c7, 0x2e400)\r\n    storage             command_queue.go:177        (*CommandQueue).getWait(#18943, #104238, #57186, 0x1f7, 0x1f7, 0, 0, 0)\r\n    storage             replica.go:1222             (*Replica).beginCmds(#32008, #254751, #81445, #72445, #22867, #49198, 0)\r\n    storage             replica.go:1628             (*Replica).tryAddWriteCmd(#32008, #254751, #81445, #255981, 0, #245, 0x5, 0x8d4, 0, 0, ...)\r\n    storage             replica.go:1603             (*Replica).addWriteCmd(#32008, #254751, #81445, #255981, 0, #245, 0x5, 0x8d4, 0, 0, ...)\r\n    storage             replica.go:1104             (*Replica).Send(#32008, #254751, #81445, #255981, 0, #245, 0x5, 0x8d4, 0, 0, ...)\r\n    storage             store.go:2333               (*Store).Send(#873, #254751, #81444, #255981, 0, #245, 0x5, 0x8d4, 0, 0, ...)\r\n    storage             stores.go:187               (*Stores).Send(#804, #254751, #81443, 0, 0, #245, 0x5, 0x8d4, 0, 0, ...)\r\n    server              node.go:843                 (*Node).batchInternal.func1(0, 0)\r\n    stop                stopper.go:245              (*Stopper).RunTaskWithErr(#751, #22868, 0, 0)\r\n    server              node.go:854                 (*Node).batchInternal(#519, #254751, #81441, #72444, #81441, #46953, 0x603fa7)\r\n    server              node.go:874                 (*Node).Batch(#519, #254751, #81441, #72444, 0, 0xad1, 0xad1)\r\n    roachpb             api.pb.go:1512              _Internal_Batch_Handler(#41, #519, #254751, #81440, #69183, 0, 0, 0, 0, #255031)\r\n    grpc                server.go:611               (*Server).processUnaryRPC(#691, #110, #1601, #45897, #726, #75, 0, 0, 0)\r\n    grpc                server.go:769               (*Server).handleStream(#691, #110, #1601, #45897, 0)\r\n    grpc                server.go:422               (*Server).serveStreams.func1.1(#1519, #691, #110, #1601, #45897)\r\n```\r\n\r\nThis is similar to what I saw with race builds in #10388. "},"comment":{"url":"https://api.github.com/repos/cockroachdb/cockroach/issues/comments/262083833","html_url":"https://github.com/cockroachdb/cockroach/issues/10427#issuecomment-262083833","issue_url":"https://api.github.com/repos/cockroachdb/cockroach/issues/10427","id":262083833,"user":{"login":"a-robinson","id":7085343,"avatar_url":"https://avatars.githubusercontent.com/u/7085343?v=3","gravatar_id":"","url":"https://api.github.com/users/a-robinson","html_url":"https://github.com/a-robinson","followers_url":"https://api.github.com/users/a-robinson/followers","following_url":"https://api.github.com/users/a-robinson/following{/other_user}","gists_url":"https://api.github.com/users/a-robinson/gists{/gist_id}","starred_url":"https://api.github.com/users/a-robinson/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/a-robinson/subscriptions","organizations_url":"https://api.github.com/users/a-robinson/orgs","repos_url":"https://api.github.com/users/a-robinson/repos","events_url":"https://api.github.com/users/a-robinson/events{/privacy}","received_events_url":"https://api.github.com/users/a-robinson/received_events","type":"User","site_admin":false},"created_at":"2016-11-21T22:11:22Z","updated_at":"2016-11-21T22:11:22Z","body":"Particularly, it's likely worth understanding what's causing https://github.com/cockroachdb/cockroach/blob/a7b7048c973d852e68d84f1c5fa042e74c5dcb51/pkg/storage/replica_command.go#L706 to consume 2.5 gigs of memory."}}
{"actor":{"display_login":"a-robinson"}}