Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

github.com/cockroachdb/cockroach/pkg/sql/logictest: TestParallel/subquery_retry_multinode failed under stress #26030

Closed
cockroach-teamcity opened this issue May 24, 2018 · 1 comment
Closed

github.com/cockroachdb/cockroach/pkg/sql/logictest: TestParallel/subquery_retry_multinode failed under stress #26030

cockroach-teamcity opened this issue May 24, 2018 · 1 comment
Assignees
@windchan7
Labels
A-kv-client Relating to the KV client and the KV interface. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone
2.1

Comments

@cockroach-teamcity
Copy link
Member

SHA: https://github.com/cockroachdb/cockroach/commits/9c197a359cf35d495425365cd22c3169e8cc0335

Parameters:

TAGS=
GOFLAGS=-race

Failed test: https://teamcity.cockroachdb.com/viewLog.html?buildId=676609&tab=buildLog


I180524 07:38:29.494264 923 storage/replica_proposal.go:202  [n1,s1,r4/1:/System/{NodeLive…-tsd}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.070547362,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.070547362,0
I180524 07:38:29.604087 5986 storage/replica_command.go:863  [split,n1,s1,r24/1:/System/{StatusNo…-tsd}] initiating a split of this range at key /System/StatusNode/3 [r26]
I180524 07:38:29.771800 1771 server/status/runtime.go:219  [n3] runtime stats: 1.2 GiB RSS, 1121 goroutines, 68 MiB/32 MiB/127 MiB GO alloc/idle/total, 155 MiB/191 MiB CGO alloc/total, 1169.66cgo/sec, 1.03/0.09 %(u/s)time, 0.02 %gc (5x)
I180524 07:38:30.638810 2146 server/status/runtime.go:219  [n4] runtime stats: 1.2 GiB RSS, 1113 goroutines, 52 MiB/47 MiB/127 MiB GO alloc/idle/total, 154 MiB/191 MiB CGO alloc/total, 1393.83cgo/sec, 1.07/0.09 %(u/s)time, 0.02 %gc (6x)
I180524 07:38:30.695094 5743 sql/event_log.go:126  [n1,client=127.0.0.1:40098,user=root] Event: "create_database", target: 52, info: {DatabaseName:test Statement:CREATE DATABASE test User:root}
I180524 07:38:30.882129 6015 storage/replica_command.go:863  [split,n1,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/52 [r27]
I180524 07:38:31.215144 1022 storage/replica_proposal.go:202  [n1,s1,r10/1:/Table/1{3-4}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147483.052160485,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147483.052160485,0
I180524 07:38:31.317561 6168 storage/replica_command.go:863  [split,n1,s1,r25/1:/Table/1{3/1/2018…-4}] initiating a split of this range at key /Table/13/1/2018-05-24T07:38:14.504903Z/350870225259921410 [r28]
I180524 07:38:31.349691 1039 storage/replica_proposal.go:202  [n1,s1,r5/1:/System/ts{d-e}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.962241955,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.962241955,0
W180524 07:38:31.467872 1602 storage/node_liveness.go:528  [n2,hb] slow heartbeat took 1.2s
I180524 07:38:31.718167 2491 server/status/runtime.go:219  [n5] runtime stats: 1.2 GiB RSS, 1121 goroutines, 73 MiB/26 MiB/127 MiB GO alloc/idle/total, 154 MiB/192 MiB CGO alloc/total, 1421.55cgo/sec, 1.07/0.09 %(u/s)time, 0.01 %gc (5x)
I180524 07:38:31.815477 6210 storage/replica_command.go:863  [split,n1,s1,r23/1:/System/ts{d/cr.no…-e}] initiating a split of this range at key /System/tsd/cr.node.security.certificate.expiration.node/2/10s/2018-05-24T07:00:00Z [r29]
W180524 07:38:31.823564 6051 storage/replica.go:3131  [n1,s1,r5/1:/System/tsd{-/cr.nod…}] context canceled before proposing: 1 HeartbeatTxn
I180524 07:38:31.898998 6059 storage/replica.go:3320  [n2,s2,r21/2:/Table/5{0-1}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n5,s5):4 (n2,s2):2 (n3,s3):3] next=5
W180524 07:38:31.955700 1106 storage/node_liveness.go:528  [n1,hb] slow heartbeat took 1.4s
I180524 07:38:31.974358 5769 storage/replica_command.go:1777  [replicate,n1,s1,r5/1:/System/tsd{-/cr.nod…}] change replicas (ADD_REPLICA (n2,s2):4): read existing descriptor r5:/System/tsd{-/cr.node.gossip.infos.sent/1/10s/2018-05-24T07:00:00Z} [(n1,s1):1, (n4,s4):2, (n3,s3):3, next=4]
I180524 07:38:31.976255 1795 gossip/gossip.go:1307  [n3] node has connected to cluster via gossip
W180524 07:38:32.221953 1041 storage/store.go:3633  [n1,s1] handle raft ready: 0.6s [processed=0]
I180524 07:38:32.301860 6112 storage/replica_raftstorage.go:520  [replicate,n4,s4,r8/2:/Table/1{1-2}] generated preemptive snapshot 2f748837 at index 42
I180524 07:38:32.526660 1795 storage/stores.go:241  [n3] wrote 4 node addresses to persistent storage
I180524 07:38:32.530164 6214 storage/replica_raftstorage.go:520  [replicate,n3,s3,r12/2:/Table/1{5-6}] generated preemptive snapshot 72e98583 at index 38
I180524 07:38:32.532622 6112 storage/store_snapshot.go:605  [replicate,n4,s4,r8/2:/Table/1{1-2}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 32, rate-limit: 2.0 MiB/sec, 183ms
I180524 07:38:32.698889 6250 storage/replica_raftstorage.go:730  [n2,s2,r8/?:{-}] applying preemptive snapshot at index 42 (id=2f748837, encoded size=9143, 1 rocksdb batches, 32 log entries)
I180524 07:38:32.758319 6214 storage/store_snapshot.go:605  [replicate,n3,s3,r12/2:/Table/1{5-6}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 28, rate-limit: 2.0 MiB/sec, 226ms
I180524 07:38:32.798311 6269 storage/replica_raftstorage.go:730  [n2,s2,r12/?:{-}] applying preemptive snapshot at index 38 (id=72e98583, encoded size=8137, 1 rocksdb batches, 28 log entries)
E180524 07:38:33.103361 5769 storage/queue.go:778  [replicate,n1,s1,r5/1:/System/tsd{-/cr.nod…}] change replicas of r5 failed: descriptor changed: [expected] r5:/System/ts{d-e} [(n1,s1):1, (n4,s4):2, (n3,s3):3, next=4] != [actual] r5:/System/tsd{-/cr.node.gossip.infos.sent/1/10s/2018-05-24T07:00:00Z} [(n1,s1):1, (n4,s4):2, (n3,s3):3, next=4]: unexpected value: raw_bytes:"\245\304\244\251\003\010\005\022\004\004tsd\032&\004tsd\022cr.node.gossip.infos.sent\000\001\211\370\006y\0171\"\006\010\001\020\001\030\001\"\006\010\004\020\004\030\002\"\006\010\003\020\003\030\003(\004" timestamp:<wall_time:1527147508838320697 > 
W180524 07:38:33.166569 1844 storage/node_liveness.go:528  [n3,hb] slow heartbeat took 1.9s
W180524 07:38:33.369250 2182 storage/node_liveness.go:528  [n4,hb] slow heartbeat took 1.2s
I180524 07:38:33.396046 6325 storage/replica_raftstorage.go:520  [replicate,n1,s1,r11/1:/Table/1{4-5}] generated preemptive snapshot 34e7f406 at index 24
I180524 07:38:33.462411 6342 storage/replica_raftstorage.go:520  [replicate,n5,s5,r19/2:/Table/2{2-3}] generated preemptive snapshot 190d38a8 at index 38
I180524 07:38:33.473151 6250 storage/replica_raftstorage.go:736  [n2,s2,r8/?:/Table/1{1-2}] applied preemptive snapshot in 774ms [clear=0ms batch=0ms entries=487ms commit=91ms]
I180524 07:38:33.503155 6342 storage/store_snapshot.go:605  [replicate,n5,s5,r19/2:/Table/2{2-3}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 28, rate-limit: 2.0 MiB/sec, 39ms
I180524 07:38:33.519899 1450 gossip/gossip.go:1307  [n2] node has connected to cluster via gossip
I180524 07:38:33.522049 6269 storage/replica_raftstorage.go:736  [n2,s2,r12/?:/Table/1{5-6}] applied preemptive snapshot in 688ms [clear=0ms batch=0ms entries=405ms commit=75ms]
I180524 07:38:33.541861 6345 storage/replica_raftstorage.go:730  [n2,s2,r19/?:{-}] applying preemptive snapshot at index 38 (id=190d38a8, encoded size=7654, 1 rocksdb batches, 28 log entries)
I180524 07:38:33.550976 6325 storage/store_snapshot.go:605  [replicate,n1,s1,r11/1:/Table/1{4-5}] streamed snapshot to (n5,s5):?: kv pairs: 10, log entries: 14, rate-limit: 2.0 MiB/sec, 121ms
I180524 07:38:33.568949 6112 storage/replica_command.go:1777  [replicate,n4,s4,r8/2:/Table/1{1-2}] change replicas (ADD_REPLICA (n2,s2):5): read existing descriptor r8:/Table/1{1-2} [(n5,s5):4, (n4,s4):2, (n3,s3):3, next=5]
I180524 07:38:33.585980 1450 storage/stores.go:241  [n2] wrote 4 node addresses to persistent storage
I180524 07:38:33.635409 2341 storage/store.go:3508  [n1,s1,r21/1:/Table/5{0-1}] added to replica GC queue (peer suggestion)
I180524 07:38:33.821604 2341 storage/store.go:3508  [n1,s1,r21/1:/Table/5{0-1}] added to replica GC queue (peer suggestion)
I180524 07:38:33.659670 6345 storage/replica_raftstorage.go:736  [n2,s2,r19/?:/Table/2{2-3}] applied preemptive snapshot in 117ms [clear=0ms batch=0ms entries=4ms commit=109ms]
I180524 07:38:33.698482 6296 storage/replica_raftstorage.go:730  [n5,s5,r11/?:{-}] applying preemptive snapshot at index 24 (id=34e7f406, encoded size=4682, 1 rocksdb batches, 14 log entries)
I180524 07:38:33.884535 6296 storage/replica_raftstorage.go:736  [n5,s5,r11/?:/Table/1{4-5}] applied preemptive snapshot in 14ms [clear=0ms batch=0ms entries=12ms commit=1ms]
W180524 07:38:33.901298 6314 storage/replica_backpressure.go:135  [n4,s4,r23/2:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.ca/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.security.certificate.expiration.node/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.gossip.infos.sent/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.requests.slow.distsender/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/4/10s/2018-05-24T07:00:00Z,/Min), ... 408 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/4/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:33.722040 6230 storage/store.go:2492  [replicaGC,n2,s2,r5/?:/System/ts{d-e}] removing replica
I180524 07:38:33.746552 6214 storage/replica_command.go:1777  [replicate,n3,s3,r12/2:/Table/1{5-6}] change replicas (ADD_REPLICA (n2,s2):5): read existing descriptor r12:/Table/1{5-6} [(n4,s4):4, (n3,s3):2, (n5,s5):3, next=5]
I180524 07:38:34.026811 6230 storage/replica.go:829  [replicaGC,n2,s2,r5/?:/System/ts{d-e}] removed 438 (431+7) keys in 124ms [clear=122ms commit=2ms]
I180524 07:38:34.123987 6342 storage/replica_command.go:1777  [replicate,n5,s5,r19/2:/Table/2{2-3}] change replicas (ADD_REPLICA (n2,s2):5): read existing descriptor r19:/Table/2{2-3} [(n3,s3):4, (n5,s5):2, (n4,s4):3, next=5]
I180524 07:38:34.145937 6325 storage/replica_command.go:1777  [replicate,n1,s1,r11/1:/Table/1{4-5}] change replicas (ADD_REPLICA (n5,s5):4): read existing descriptor r11:/Table/1{4-5} [(n1,s1):1, (n4,s4):2, (n2,s2):3, next=4]
I180524 07:38:34.152222 6222 storage/store.go:2492  [replicaGC,n1,s1,r21/1:/Table/5{0-1}] removing replica
I180524 07:38:34.166473 6222 storage/replica.go:829  [replicaGC,n1,s1,r21/1:/Table/5{0-1}] removed 7 (0+7) keys in 13ms [clear=0ms commit=13ms]
W180524 07:38:34.660298 6420 storage/replica_backpressure.go:135  [n3,s3,r23/3:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.ca/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.security.certificate.expiration.node/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.gossip.infos.sent/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.requests.slow.distsender/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/3/10s/2018-05-24T07:00:00Z,/Min), ... 408 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/3/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:35.178438 1081 server/status/runtime.go:219  [n1] runtime stats: 1.2 GiB RSS, 1129 goroutines, 95 MiB/8.0 MiB/127 MiB GO alloc/idle/total, 157 MiB/190 MiB CGO alloc/total, 1307.62cgo/sec, 1.00/0.08 %(u/s)time, 0.03 %gc (6x)
W180524 07:38:35.415910 6401 storage/replica_backpressure.go:135  [n1,s1,r23/1:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.ca/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.security.certificate.expiration.node/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.gossip.infos.sent/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.requests.slow.distsender/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/3/10s/2018-05-24T07:00:00Z,/Min), ... 408 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/3/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/3/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:35.450496 6500 storage/store.go:2492  [replicaGC,n2,s2,r8/?:/Table/1{1-2}] removing replica
I180524 07:38:35.459342 6500 storage/replica.go:829  [replicaGC,n2,s2,r8/?:/Table/1{1-2}] removed 6 (0+6) keys in 8ms [clear=0ms commit=8ms]
I180524 07:38:35.469263 849 sql/logictest/parallel_test.go:236  Test setup done
I180524 07:38:35.469541 849 sql/logictest/parallel_test.go:159  testdata/parallel_test/subquery_retry_multinode/test.yaml: run list 0: 0:setup
W180524 07:38:36.261964 6495 storage/replica_backpressure.go:135  [n1,s1,r23/1:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.ca/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.security.certificate.expiration.node/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.gossip.infos.sent/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.requests.slow.distsender/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/2/10s/2018-05-24T07:00:00Z,/Min), ... 408 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/2/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:36.569767 6325 storage/replica.go:3320  [n1,s1,r11/1:/Table/1{4-5}] proposing ADD_REPLICA((n5,s5):4): updated=[(n1,s1):1 (n4,s4):2 (n2,s2):3 (n5,s5):4] next=5
W180524 07:38:36.591704 1083 server/node.go:802  [n1,summaries] health alerts detected: {Alerts:[{StoreID:1 Category:METRICS Description:requests.backpressure.split Value:3} {StoreID:1 Category:METRICS Description:queue.replicate.process.failure Value:1}]}
I180524 07:38:37.429853 6609 storage/store.go:2492  [replicaGC,n2,s2,r19/?:/Table/2{2-3}] removing replica
I180524 07:38:37.573079 6609 storage/replica.go:829  [replicaGC,n2,s2,r19/?:/Table/2{2-3}] removed 6 (0+6) keys in 96ms [clear=0ms commit=96ms]
I180524 07:38:37.872442 1608 storage/replica_proposal.go:202  [n2,s2,r11/3:/Table/1{4-5}] new range lease repl=(n2,s2):3 seq=4 start=1527147517.186510911,0 epo=1 pro=1527147517.186554290,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147483.337628955,0
I180524 07:38:37.962673 6589 storage/replica_raftstorage.go:520  [replicate,n1,s1,r7/1:/Table/{SystemCon…-11}] generated preemptive snapshot 8b35f36d at index 40
I180524 07:38:38.038654 6589 storage/store_snapshot.go:605  [replicate,n1,s1,r7/1:/Table/{SystemCon…-11}] streamed snapshot to (n2,s2):?: kv pairs: 67, log entries: 30, rate-limit: 2.0 MiB/sec, 61ms
I180524 07:38:38.080563 1065 storage/replica_proposal.go:202  [n1,s1,r24/1:/System/{StatusNo…-tsd}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.070547362,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.070547362,0
I180524 07:38:38.183657 6681 storage/replica_command.go:863  [split,n1,s1,r26/1:/System/{StatusNo…-tsd}] initiating a split of this range at key /System/StatusNode/4 [r30]
I180524 07:38:38.185839 6723 storage/replica_raftstorage.go:730  [n2,s2,r7/?:{-}] applying preemptive snapshot at index 40 (id=8b35f36d, encoded size=19336, 1 rocksdb batches, 30 log entries)
I180524 07:38:38.188412 1034 storage/replica_proposal.go:202  [n1,s1,r22/1:/{Table/51-Max}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147491.390409721,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147491.390409721,0
I180524 07:38:38.349861 926 storage/replica_proposal.go:202  [n1,s1,r23/1:/System/ts{d/cr.no…-e}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.962241955,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147485.962241955,0
I180524 07:38:38.629283 6807 storage/replica_command.go:863  [split,n1,s1,r29/1:/System/ts{d/cr.no…-e}] initiating a split of this range at key /System/tsd/cr.node.sql.distsql.service.latency-p99.9/3/10s/2018-05-24T07:00:00Z [r31]
I180524 07:38:38.747080 1577 server/status/runtime.go:219  [n2] runtime stats: 1.2 GiB RSS, 1161 goroutines, 87 MiB/11 MiB/127 MiB GO alloc/idle/total, 158 MiB/192 MiB CGO alloc/total, 1244.64cgo/sec, 1.01/0.09 %(u/s)time, 0.04 %gc (4x)
I180524 07:38:38.894137 5743 sql/event_log.go:126  [n1,client=127.0.0.1:40098,user=root] Event: "create_table", target: 53, info: {TableName:test.public.t Statement:CREATE TABLE t (k INT, filler STRING) User:root}
--- progress: testdata/parallel_test/subquery_retry_multinode/setup: 1 statements/queries
I180524 07:38:38.896418 6488 sql/logictest/logic.go:814  --- progress: testdata/parallel_test/subquery_retry_multinode/setup: 1 statements/queries
I180524 07:38:38.910347 6850 storage/replica.go:3320  [n4,s4,r8/2:/Table/1{1-2}] proposing ADD_REPLICA((n2,s2):5): updated=[(n5,s5):4 (n4,s4):2 (n3,s3):3 (n2,s2):5] next=6
I180524 07:38:39.035582 6750 storage/replica_command.go:863  [split,n1,s1,r27/1:/{Table/52-Max}] initiating a split of this range at key /Table/53 [r32]
I180524 07:38:39.593339 6888 storage/replica.go:3320  [n5,s5,r19/2:/Table/2{2-3}] proposing ADD_REPLICA((n2,s2):5): updated=[(n3,s3):4 (n5,s5):2 (n4,s4):3 (n2,s2):5] next=6
I180524 07:38:39.796671 1771 server/status/runtime.go:219  [n3] runtime stats: 1.3 GiB RSS, 1179 goroutines, 62 MiB/42 MiB/131 MiB GO alloc/idle/total, 159 MiB/193 MiB CGO alloc/total, 1174.90cgo/sec, 1.00/0.08 %(u/s)time, 0.04 %gc (5x)
I180524 07:38:40.011077 6825 storage/replica.go:3320  [n3,s3,r12/2:/Table/1{5-6}] proposing ADD_REPLICA((n2,s2):5): updated=[(n4,s4):4 (n3,s3):2 (n5,s5):3 (n2,s2):5] next=6
W180524 07:38:40.384365 6995 storage/replica_backpressure.go:135  [n1,s1,r29/1:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.node/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.9/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p90/2/10s/2018-05-24T07:00:00Z,/Min), ... 384 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/2/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/2/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:40.712797 2146 server/status/runtime.go:219  [n4] runtime stats: 1.3 GiB RSS, 1186 goroutines, 74 MiB/27 MiB/131 MiB GO alloc/idle/total, 159 MiB/193 MiB CGO alloc/total, 924.16cgo/sec, 0.97/0.08 %(u/s)time, 0.04 %gc (4x)
I180524 07:38:40.816919 7000 storage/replica_command.go:1777  [replicate,n5,s5,r19/2:/Table/2{2-3}] change replicas (REMOVE_REPLICA (n4,s4):3): read existing descriptor r19:/Table/2{2-3} [(n3,s3):4, (n5,s5):2, (n4,s4):3, (n2,s2):5, next=6]
W180524 07:38:40.920537 6859 storage/replica_backpressure.go:135  [n4,s4,r29/2:/System/ts{d/cr.no…-e}] applying backpressure to limit range growth on batch Merge [/System/tsd/cr.node.security.certificate.expiration.node/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.aborts/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.commits1PC/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.autoretries/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.abandons/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-max/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.999/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99.9/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p90/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p75/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.durations-p50/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-max/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.999/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99.9/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p99/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.node.txn.restarts-p90/4/10s/2018-05-24T07:00:00Z,/Min), ... 384 skipped ..., Merge [/System/tsd/cr.store.queue.replicate.removereplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.removedeadreplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.rebalancereplica/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicate.transferlease/4/10s/2018-05-24T07:00:00Z,/Min), Merge [/System/tsd/cr.store.queue.replicagc.removereplica/4/10s/2018-05-24T07:00:00Z,/Min)
I180524 07:38:41.208774 6857 storage/replica_command.go:1777  [replicate,n2,s2,r11/3:/Table/1{4-5}] change replicas (REMOVE_REPLICA (n1,s1):1): read existing descriptor r11:/Table/1{4-5} [(n1,s1):1, (n4,s4):2, (n2,s2):3, (n5,s5):4, next=5]
I180524 07:38:41.609560 7090 storage/replica_command.go:1777  [replicate,n3,s3,r12/2:/Table/1{5-6}] change replicas (REMOVE_REPLICA (n4,s4):4): read existing descriptor r12:/Table/1{5-6} [(n4,s4):4, (n3,s3):2, (n5,s5):3, (n2,s2):5, next=6]
I180524 07:38:41.710702 2491 server/status/runtime.go:219  [n5] runtime stats: 1.3 GiB RSS, 1196 goroutines, 91 MiB/11 MiB/131 MiB GO alloc/idle/total, 160 MiB/194 MiB CGO alloc/total, 918.19cgo/sec, 0.94/0.09 %(u/s)time, 0.04 %gc (4x)
I180524 07:38:41.957188 1024 storage/replica_proposal.go:202  [n1,s1,r25/1:/Table/1{3/1/2018…-4}] new range lease repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147483.052160485,0 following repl=(n1,s1):1 seq=3 start=1527147474.437138439,0 epo=1 pro=1527147483.052160485,0
I180524 07:38:42.411260 2578 storage/replica_proposal.go:202  [n5,s5,r8/4:/Table/1{1-2}] new range lease repl=(n5,s5):4 seq=4 start=1527147520.110386245,0 epo=1 pro=1527147520.110400514,0 following repl=(n4,s4):2 seq=3 start=1527147483.476976488,1 epo=1 pro=1527147483.615520730,0
I180524 07:38:42.443161 7127 storage/replica_raftstorage.go:520  [raftsnapshot,n5,s5,r19/2:/Table/2{2-3}] generated Raft snapshot ecd0847c at index 44
I180524 07:38:42.563454 7127 storage/store_snapshot.go:605  [raftsnapshot,n5,s5,r19/2:/Table/2{2-3}] streamed snapshot to (n2,s2):5: kv pairs: 14, log entries: 34, rate-limit: 8.0 MiB/sec, 106ms
I180524 07:38:42.567587 7103 storage/replica_raftstorage.go:730  [n2,s2,r19/5:{-}] applying Raft snapshot at index 44 (id=ecd0847c, encoded size=10089, 1 rocksdb batches, 34 log entries)
W180524 07:38:42.572688 1602 storage/node_liveness.go:528  [n2,hb] slow heartbeat took 3.3s
I180524 07:38:42.666536 7089 storage/replica_raftstorage.go:520  [replicate,n4,s4,r14/3:/Table/1{7-8}] generated preemptive snapshot 3c37e7f5 at index 49
I180524 07:38:42.689628 7060 storage/replica_raftstorage.go:520  [raftsnapshot,n4,s4,r8/2:/Table/1{1-2}] generated Raft snapshot f6e68c24 at index 50
I180524 07:38:42.755435 7089 storage/store_snapshot.go:605  [replicate,n4,s4,r14/3:/Table/1{7-8}] streamed snapshot to (n5,s5):?: kv pairs: 14, log entries: 39, rate-limit: 2.0 MiB/sec, 88ms
I180524 07:38:42.816734 7251 storage/replica_raftstorage.go:730  [n5,s5,r14/?:{-}] applying preemptive snapshot at index 49 (id=3c37e7f5, encoded size=10850, 1 rocksdb batches, 39 log entries)
F180524 07:38:42.950647 1653 storage/replica.go:3873  [n2,s2,r11/3:/Table/1{4-5}] while purging index %d: while purging index 33: IO error: /go/src/github.com/cockroachdb/cockroach/artifacts/cockroach-auxiliary127175424/sideloading/11/11.3/i33.t7: File not found
goroutine 1653 [running]:
github.com/cockroachdb/cockroach/pkg/util/log.getStacks(0x4bfc601, 0xc4204b0060, 0x0, 0x12)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:956 +0xdd
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).outputLogEntry(0x4238220, 0xc400000004, 0x3d289a1, 0x12, 0xf21, 0xc4206751e0, 0xd0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:834 +0x7f4
github.com/cockroachdb/cockroach/pkg/util/log.addStructured(0x3183f80, 0xc420c899e0, 0xc400000004, 0x2, 0x2c3dc84, 0x6, 0xc424525b88, 0x2, 0x2)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/structured.go:154 +0x31e
github.com/cockroachdb/cockroach/pkg/util/log.logDepth(0x3183f80, 0xc420c899e0, 0x1, 0x4, 0x2c3dc84, 0x6, 0xc424525b88, 0x2, 0x2)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:55 +0x9a
github.com/cockroachdb/cockroach/pkg/util/log.Fatalf(0x3183f80, 0xc420c899e0, 0x2c3dc84, 0x6, 0xc424525b88, 0x2, 0x2)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:149 +0x90
github.com/cockroachdb/cockroach/pkg/storage.fatalOnRaftReadyErr(0x3183f80, 0xc420c899e0, 0x2c59c7c, 0x16, 0x31619e0, 0xc424610620)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:3873 +0x219
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processRequestQueue.func1(0x3183f80, 0xc420c899e0, 0xc424fce000, 0x3183f80)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3576 +0x215
github.com/cockroachdb/cockroach/pkg/storage.(*Store).withReplicaForRequest(0xc42065e000, 0x3183f80, 0xc420c899e0, 0xc4211429c0, 0xc424525e98, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3178 +0x169
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processRequestQueue(0xc42065e000, 0x3183f80, 0xc421349020, 0xb)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3563 +0x302
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc4216002d0, 0x3183f80, 0xc421349020)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:226 +0x2f2
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421349020)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc42033a290, 0xc420aa0ab0, 0xc42033a280)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1 [chan receive]:
testing.(*T).Run(0xc4201c0960, 0x2c48a8c, 0xc, 0x2d5b8d0, 0xc4206d5c01)
	/usr/local/go/src/testing/testing.go:825 +0x597
testing.runTests.func1(0xc4201c0960)
	/usr/local/go/src/testing/testing.go:1063 +0xa5
testing.tRunner(0xc4201c0960, 0xc4206d5d68)
	/usr/local/go/src/testing/testing.go:777 +0x16e
testing.runTests(0xc4202946e0, 0x3fef7a0, 0x4, 0x4, 0xbeb9b8d29eb7aa59)
	/usr/local/go/src/testing/testing.go:1061 +0x4e2
testing.(*M).Run(0xc4201c4700, 0x0)
	/usr/local/go/src/testing/testing.go:978 +0x2ce
github.com/cockroachdb/cockroach/pkg/sql/logictest.TestMain(0xc4201c4700)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/logictest/main_test.go:37 +0x15e
main.main()
	_testmain.go:46 +0x22b

goroutine 6 [syscall]:
os/signal.signal_recv(0x866ec1)
	/usr/local/go/src/runtime/sigqueue.go:139 +0xa6
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:22 +0x30
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:28 +0x4f

goroutine 23 [semacquire]:
sync.runtime_SemacquireMutex(0x4238278, 0x1100000000)
	/usr/local/go/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0x4238274)
	/usr/local/go/src/sync/mutex.go:134 +0x172
github.com/cockroachdb/cockroach/pkg/util/syncutil.(*Mutex).Lock(0x4238274)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/syncutil/mutex_sync.go:32 +0x3b
github.com/cockroachdb/cockroach/pkg/util/log.flushDaemon()
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1163 +0x160
created by github.com/cockroachdb/cockroach/pkg/util/log.init.0
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:591 +0x1b5

goroutine 24 [chan receive]:
github.com/cockroachdb/cockroach/pkg/util/log.signalFlusher()
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:598 +0xf2
created by github.com/cockroachdb/cockroach/pkg/util/log.init.0
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:592 +0x1cd

goroutine 25 [select, locked to thread]:
runtime.gopark(0x2d5fb10, 0x0, 0x2c3f22c, 0x6, 0x18, 0x1)
	/usr/local/go/src/runtime/proc.go:291 +0xf9
runtime.selectgo(0xc42007df50, 0xc4204b0120)
	/usr/local/go/src/runtime/select.go:392 +0x11d4
runtime.ensureSigM.func1()
	/usr/local/go/src/runtime/signal_unix.go:549 +0x19f
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:2361 +0x1

goroutine 930 [select]:
net.(*pipe).read(0xc4201c5a80, 0xc4218aa400, 0x400, 0x400, 0x16a5, 0x2000, 0xc421959680)
	/usr/local/go/src/net/pipe.go:164 +0x290
net.(*pipe).Read(0xc4201c5a80, 0xc4218aa400, 0x400, 0x400, 0xc420441720, 0xc4219596b0, 0xb5d82a)
	/usr/local/go/src/net/pipe.go:147 +0x61
crypto/tls.(*block).readFromUntil(0xc4218e33b0, 0x7faa39d151f8, 0xc4201c5a80, 0x5, 0xc4201c5a80, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:493 +0x114
crypto/tls.(*Conn).readRecord(0xc421548e00, 0x2d5fc17, 0xc421548f20, 0xc4218aa40d)
	/usr/local/go/src/crypto/tls/conn.go:595 +0x134
crypto/tls.(*Conn).Read(0xc421548e00, 0xc421c60000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:1156 +0x160
bufio.(*Reader).Read(0xc421ed7aa0, 0xc421f408f8, 0x9, 0x9, 0x1060100000020, 0x8, 0x354effff5a53925b)
	/usr/local/go/src/bufio/bufio.go:216 +0x740
io.ReadAtLeast(0x315e5c0, 0xc421ed7aa0, 0xc421f408f8, 0x9, 0x9, 0x9, 0x316a500, 0xc4258a0460, 0x84d3c0)
	/usr/local/go/src/io/io.go:309 +0x94
io.ReadFull(0x315e5c0, 0xc421ed7aa0, 0xc421f408f8, 0x9, 0x9, 0x8, 0x8, 0x867fa2)
	/usr/local/go/src/io/io.go:327 +0x73
github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2.readFrameHeader(0xc421f408f8, 0x9, 0x9, 0x315e5c0, 0xc421ed7aa0, 0x0, 0x0, 0xc42192cfa0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2/frame.go:237 +0x8f
github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2.(*Framer).ReadFrame(0xc421f408c0, 0xc42192cfa0, 0xc42192cfa0, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2/frame.go:492 +0x10f
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.(*http2Server).HandleStreams(0xc420afe000, 0xc4208758f0, 0x2d5ed70)
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_server.go:427 +0xd6
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).serveStreams(0xc42202fa40, 0x319b540, 0xc420afe000)
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:676 +0x16f
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).handleRawConn.func2()
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:631 +0x54
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).handleRawConn.func3(0xc4204a24c0, 0xc42202fa40, 0x7faa3aeb8da8, 0xc420afe000)
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:639 +0x35
created by github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).handleRawConn
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:638 +0x7c7

goroutine 1060 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0xb406a49900000cae)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112c00)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112c00)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bfb30, 0xc421a25cb0, 0xc4203bfb20)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 15 [chan receive]:
testing.(*T).Run(0xc4201c0a50, 0xc42049c887, 0x18, 0xc4203f48c0, 0x1)
	/usr/local/go/src/testing/testing.go:825 +0x597
github.com/cockroachdb/cockroach/pkg/sql/logictest.TestParallel(0xc4201c0a50)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/logictest/parallel_test.go:254 +0x23a
testing.tRunner(0xc4201c0a50, 0x2d5b8d0)
	/usr/local/go/src/testing/testing.go:777 +0x16e
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:824 +0x565

goroutine 849 [chan receive]:
github.com/cockroachdb/cockroach/pkg/sql/logictest.(*parallelTest).run(0xc420c26c00, 0xc42049c870, 0x2f)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/logictest/parallel_test.go:172 +0xf29
github.com/cockroachdb/cockroach/pkg/sql/logictest.TestParallel.func1(0xc42103cd20)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/logictest/parallel_test.go:256 +0x13f
testing.tRunner(0xc42103cd20, 0xc4203f48c0)
	/usr/local/go/src/testing/testing.go:777 +0x16e
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:824 +0x565

goroutine 3534 [IO wait]:
internal/poll.runtime_pollWait(0x7faa35c50400, 0x72, 0x4009568)
	/usr/local/go/src/runtime/netpoll.go:173 +0x5e
internal/poll.(*pollDesc).wait(0xc42182d318, 0x72, 0x3164000, 0x4009568, 0xffffffffffffffff)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:85 +0xe5
internal/poll.(*pollDesc).waitRead(0xc42182d318, 0xc42548f400, 0x400, 0x400)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x4b
internal/poll.(*FD).Read(0xc42182d300, 0xc42548f400, 0x400, 0x400, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:157 +0x22a
net.(*netFD).Read(0xc42182d300, 0xc42548f400, 0x400, 0x400, 0xc41fe95d68, 0xc41fe95d67, 0x0)
	/usr/local/go/src/net/fd_unix.go:202 +0x66
net.(*conn).Read(0xc4204d0ca8, 0xc42548f400, 0x400, 0x400, 0xc421df56f0, 0x8135ad, 0xc420f2a000)
	/usr/local/go/src/net/net.go:176 +0x85
crypto/tls.(*block).readFromUntil(0xc424cb50e0, 0x7faa39d1afa0, 0xc4204d0ca8, 0x5, 0xc4204d0ca8, 0x7faa3afa81e8)
	/usr/local/go/src/crypto/tls/conn.go:493 +0x114
crypto/tls.(*Conn).readRecord(0xc421477880, 0x2d5fc17, 0xc4214779a0, 0x37)
	/usr/local/go/src/crypto/tls/conn.go:595 +0x134
crypto/tls.(*Conn).Read(0xc421477880, 0xc42516e000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:1156 +0x160
bufio.(*Reader).Read(0xc4241b7ec0, 0xc420239378, 0x9, 0x9, 0x0, 0x0, 0xc421df5c58)
	/usr/local/go/src/bufio/bufio.go:216 +0x740
io.ReadAtLeast(0x315e5c0, 0xc4241b7ec0, 0xc420239378, 0x9, 0x9, 0x9, 0x816e0a, 0xc420ae4400, 0x10)
	/usr/local/go/src/io/io.go:309 +0x94
io.ReadFull(0x315e5c0, 0xc4241b7ec0, 0xc420239378, 0x9, 0x9, 0xc4214c2828, 0x2, 0x867fa2)
	/usr/local/go/src/io/io.go:327 +0x73
github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2.readFrameHeader(0xc420239378, 0x9, 0x9, 0x315e5c0, 0xc4241b7ec0, 0x0, 0x0, 0xc4210fe150, 0x316ad40)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2/frame.go:237 +0x8f
github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2.(*Framer).ReadFrame(0xc420239340, 0xc423cd8210, 0xc423cd8200, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/net/http2/frame.go:492 +0x10f
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.(*http2Client).reader(0xc425ac78c0)
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_client.go:1129 +0x1fe
created by github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.newHTTP2Client
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_client.go:265 +0x10fc

goroutine 1535 [semacquire]:
sync.runtime_notifyListWait(0xc42150e810, 0x438464230000047c)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc42150e800)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc4216002d0, 0x3183f80, 0xc421056de0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421056de0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420413b80, 0xc420aa0ab0, 0xc420413b70)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1088 [select]:
github.com/cockroachdb/cockroach/pkg/sql.(*Server).Start.func1(0x3183f80, 0xc4215af020)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:296 +0x1af
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203fe410, 0xc421a25cb0, 0xc42196b3e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1018 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000ca9)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112780)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112780)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf480, 0xc421a25cb0, 0xc4203bf460)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1020 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x8e24277d00000cb6)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4211127e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4211127e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf4c0, 0xc421a25cb0, 0xc4203bf4b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1021 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x20fa3e100000cab)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112840)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112840)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf4e0, 0xc421a25cb0, 0xc4203bf4d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1019 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0xc824fe4a00000c9e)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4211127b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4211127b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf4a0, 0xc421a25cb0, 0xc4203bf490)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1023 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000ca8)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4211128a0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4211128a0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf520, 0xc421a25cb0, 0xc4203bf510)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1024 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0xd7acc20200000cb1)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4211128d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4211128d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf540, 0xc421a25cb0, 0xc4203bf530)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1025 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000cc1)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112900)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112900)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf560, 0xc421a25cb0, 0xc4203bf550)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1026 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x6be931f000000cb4)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112930)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112930)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf580, 0xc421a25cb0, 0xc4203bf570)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1027 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x857a7ab300000cca)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112960)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112960)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf5a0, 0xc421a25cb0, 0xc4203bf590)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1028 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000cc8)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112990)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112990)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf5c0, 0xc421a25cb0, 0xc4203bf5b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1022 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x857a7ab300000ca6)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421112870)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421112870)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf500, 0xc421a25cb0, 0xc4203bf4f0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1058 [semacquire]:
sync.runtime_SemacquireMutex(0x4233354, 0x10400000000)
	/usr/local/go/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0x4233350)
	/usr/local/go/src/sync/mutex.go:134 +0x172
github.com/cockroachdb/cockroach/pkg/util/syncutil.(*Mutex).Lock(0x4233350)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/syncutil/mutex_sync.go:32 +0x3b
github.com/cockroachdb/cockroach/pkg/util/protoutil.typeIsOrContainsVerboten(0x31b6e20, 0x2b1eb20, 0x11, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/clone.go:73 +0x47
github.com/cockroachdb/cockroach/pkg/util/protoutil.uncloneable(0x3192b40, 0xc422edf000, 0xc425acaea0, 0x2, 0x2)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/clone.go:45 +0xd1
github.com/cockroachdb/cockroach/pkg/util/protoutil.MaybeFuzz(0x3192b40, 0xc422edf000, 0xc42029d010, 0xc424b76290)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/marshal.go:36 +0x69
github.com/cockroachdb/cockroach/pkg/roachpb.(*Value).SetProto(0xc424b762f8, 0x3192b40, 0xc422edf000, 0x80, 0x854de0)
	/go/src/github.com/cockroachdb/cockroach/pkg/roachpb/data.go:394 +0x4d
github.com/cockroachdb/cockroach/pkg/storage/engine.MVCCPutProto(0x3183f80, 0xc4266618c0, 0x31a8e20, 0xc423bcd7a8, 0x0, 0xc42041dc60, 0x8, 0x20, 0x0, 0xc400000000, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/engine/mvcc.go:641 +0x8a
github.com/cockroachdb/cockroach/pkg/storage/stateloader.StateLoader.SetRangeAppliedState(0xc4206cf300, 0xc42041dc60, 0x3, 0x20, 0x3183f80, 0xc4266618c0, 0x31a8e20, 0xc423bcd7a8, 0xd, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/stateloader/stateloader.go:289 +0x401
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).applyRaftCommand(0xc421c9ce00, 0x3183f80, 0xc4266618c0, 0xc420472330, 0x8, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:5097 +0x4a6
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).processRaftCommand(0xc421c9ce00, 0x3183f80, 0xc4266618c0, 0xc420472330, 0x8, 0x6, 0xd, 0x100000001, 0x1, 0x3, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:4818 +0x53f
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).handleRaftReadyRaftMuLocked(0xc421c9ce00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:3772 +0x176c
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processRequestQueue.func1(0x3183f80, 0xc4219cbf20, 0xc421c9ce00, 0x3183f80)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3575 +0x1c3
github.com/cockroachdb/cockroach/pkg/storage.(*Store).withReplicaForRequest(0xc4212acd80, 0x3183f80, 0xc4219cbf20, 0xc423cde188, 0xc424b77e98, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3178 +0x169
github.com/cockroachdb/cockroach/pkg/storage.(*Store).processRequestQueue(0xc4212acd80, 0x3183f80, 0xc4219dc9f0, 0x1d)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3563 +0x302
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4219dc9f0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:226 +0x2f2
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4219dc9f0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bfaf0, 0xc421a25cb0, 0xc4203bfae0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1029 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000ccb)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4211129c0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4211129c0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bf5e0, 0xc421a25cb0, 0xc4203bf5d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1055 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0xc3de550200000cb7)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc4219dc8d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc4219dc8d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bfa90, 0xc421a25cb0, 0xc4203bfa60)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1059 [semacquire]:
sync.runtime_notifyListWait(0xc420c61a10, 0x9c9d99f800000cb5)
	/usr/local/go/src/runtime/sema.go:510 +0x11a
sync.(*Cond).Wait(0xc420c61a00)
	/usr/local/go/src/sync/cond.go:56 +0x8e
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc421c12900, 0x3183f80, 0xc421135650)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x9c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x3183f80, 0xc421135650)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x56
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bfb10, 0xc421a25cb0, 0xc4203bfb00)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 1082 [runnable]:
sync.runtime_SemacquireMutex(0x4233354, 0x14400000100)
	/usr/local/go/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0x4233350)
	/usr/local/go/src/sync/mutex.go:134 +0x172
github.com/cockroachdb/cockroach/pkg/util/syncutil.(*Mutex).Lock(0x4233350)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/syncutil/mutex_sync.go:32 +0x3b
github.com/cockroachdb/cockroach/pkg/util/protoutil.typeIsOrContainsVerboten(0x31b6e20, 0x2afde20, 0x11, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/clone.go:73 +0x47
github.com/cockroachdb/cockroach/pkg/util/protoutil.uncloneable(0x31907a0, 0xc4254481e0, 0x0, 0xc4254481e0, 0x30)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/clone.go:45 +0xd1
github.com/cockroachdb/cockroach/pkg/util/protoutil.MaybeFuzz(0x31907a0, 0xc4254481e0, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/protoutil/marshal.go:36 +0x69
github.com/cockroachdb/cockroach/pkg/roachpb.(*Value).SetProto(0xc42332db20, 0x31907a0, 0xc4254481e0, 0x1, 0xc4204d97b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/roachpb/data.go:394 +0x4d
github.com/cockroachdb/cockroach/pkg/ts.(*DB).tryStoreData(0xc420313280, 0x3183f80, 0xc420f16ba0, 0x1, 0xc426574a80, 0x1ca, 0x1ca, 0xc420e81ef0, 0xc420f16ba0)
	/go/src/github.com/cockroachdb/cockroach/pkg/ts/db.go:188 +0x21f
github.com/cockroachdb/cockroach/pkg/ts.(*DB).StoreData(0xc420313280, 0x3183f80, 0xc420f16ba0, 0x1, 0xc426574a80, 0x1ca, 0x1ca, 0x31a84a0, 0xc4203f4e20)
	/go/src/github.com/cockroachdb/cockroach/pkg/ts/db.go:165 +0xec
github.com/cockroachdb/cockroach/pkg/ts.(*poller).poll.func1(0x3183f80, 0xc421135a70)
	/go/src/github.com/cockroachdb/cockroach/pkg/ts/db.go:153 +0x19a
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunTask(0xc421a25cb0, 0x3183f80, 0xc421135a70, 0x2c4defd, 0xf, 0xc422517e78, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:226 +0xfb
github.com/cockroachdb/cockroach/pkg/ts.(*poller).poll(0xc4218cb9e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/ts/db.go:144 +0x199
github.com/cockroachdb/cockroach/pkg/ts.(*poller).start.func1(0x3183f80, 0xc4211139e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/ts/db.go:128 +0xbf
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203fe350, 0xc421a25cb0, 0xc4203fe330)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 53 [chan receive]:
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).gcDaemon(0xc420847200)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1210 +0x8b
created by github.com/cockroachdb/cockroach/pkg/util/log.NewSecondaryLogger
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/secondary_log.go:82 +0x4bb

goroutine 54 [chan receive]:
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).gcDaemon(0xc420847320)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1210 +0x8b
created by github.com/cockroachdb/cockroach/pkg/util/log.NewSecondaryLogger
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/secondary_log.go:82 +0x4bb

goroutine 1072 [select]:
github.com/cockroachdb/cockroach/pkg/storage.(*Store).startGossip.func4(0x3183f80, 0xc421112c90)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:1558 +0x499
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203bfe90, 0xc421a25cb0, 0xc4203a1860)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:193 +0x14b
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:186 +0xbb

goroutine 920 [select]:
net.(*pipe).read(0xc4201c5b00, 0xc4218aac00, 0x400, 0x400, 0x16a5, 0x2000, 0xc421fad6f0)
	/usr/local/go/src/net/pipe.go:164 +0x290
@cockroach-teamcity cockroach-teamcity added this to the 2.1 milestone May 24, 2018
@cockroach-teamcity cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels May 24, 2018
@tbg tbg assigned windchan7 and unassigned RaduBerinde May 30, 2018
@tbg tbg added the A-kv-client Relating to the KV client and the KV interface. label May 30, 2018
@windchan7
Copy link
Contributor

#26259

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@windchan7 windchan7

Labels
A-kv-client Relating to the KV client and the KV interface. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
2.1
Development

No branches or pull requests
4 participants
@tbg @RaduBerinde @cockroach-teamcity @windchan7