search

cockroachdb / cockroach

CockroachDB - the open source, cloud-native distributed SQL database.
https://www.cockroachlabs.com
Other
29.22k stars 3.65k forks source link

cli: Example_logging failed #123450

Open cockroach-teamcity opened 2 weeks ago

cockroach-teamcity commented 2 weeks ago

cli.Example_logging failed on release-24.1 @ 9400571541f006110b28dac7780e91dcec85140d:

Fatal error:

panic: test timed out after 14m57s

Stack: 

goroutine 8829531 [running]:
testing.(*M).startAlarm.func1()
    GOROOT/src/testing/testing.go:2366 +0x385
created by time.goFunc
    GOROOT/src/time/sleep.go:177 +0x2d
Log preceding fatal error

``` E240502 06:34:53.693661 8829129 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,replicaGC,s1,r66/1:/Table/6{4-5}] 358390 replica unavailable: (n1,s1):1 unable to serve request to r1:/{Min-System/NodeLiveness} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n3,s3):2,(n2,s2):3); closed timestamp: 1714630871.298175213,0 (2024-05-02 06:21:11); raft status: {"id":"1","term":7,"vote":"2","commit":336,"lead":"0","raftState":"StatePreCandidate","applied":336,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Min] E240502 06:34:53.694137 8829130 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r7/2:/Table/{3-4}] 358391 [n3,s3,r7/2:/Table/{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r7:/Table/{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630866.804846702,0 (2024-05-02 06:21:06); raft status: {"id":"2","term":7,"vote":"2","commit":47,"lead":"0","raftState":"StatePreCandidate","applied":47,"progress":{},"leadtransferee":"0"}: have been waiting 60.50s for slow proposal RequestLease [/Table/3] E240502 06:34:53.694573 8829131 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r10/3:/Table/{6-7}] 358392 [n3,s3,r10/3:/Table/{6-7}]: could not obtain lease: replica unavailable: (n3,s3):3 unable to serve request to r10:/Table/{6-7} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):2); closed timestamp: 1714630873.880268784,0 (2024-05-02 06:21:13); raft status: {"id":"3","term":7,"vote":"0","commit":53,"lead":"0","raftState":"StatePreCandidate","applied":53,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/6] E240502 06:34:53.695054 8829132 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r34/2:/{NamespaceTab…-Table/32}] 358393 [n3,s3,r34/2:/{NamespaceTab…-Table/32}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r34:/{NamespaceTable/Max-Table/32} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630857.224206291,0 (2024-05-02 06:20:57); raft status: {"id":"2","term":8,"vote":"2","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/NamespaceTable/Max] E240502 06:34:53.696191 8829133 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r20/1:/Table/1{7-8}] 358394 [n1,s1,r20/1:/Table/1{7-8}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r20:/Table/1{7-8} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630866.804846702,0 (2024-05-02 06:21:06); raft status: {"id":"1","term":8,"vote":"1","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/17] E240502 06:34:53.696620 8829134 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r63/1:/Table/6{1-2}] 358395 [n1,s1,r63/1:/Table/6{1-2}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r63:/Table/6{1-2} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630871.518659348,0 (2024-05-02 06:21:11); raft status: {"id":"1","term":7,"vote":"2","commit":42,"lead":"0","raftState":"StatePreCandidate","applied":42,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/Table/61] E240502 06:34:53.697081 8829135 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r3/1:/System/{NodeLive…-tsd}] 358396 [n1,s1,r3/1:/System/{NodeLive…-tsd}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r3:/System/{NodeLivenessMax-tsd} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n2,s2):2); closed timestamp: 1714630871.427326243,0 (2024-05-02 06:21:11); raft status: {"id":"1","term":7,"vote":"2","commit":114,"lead":"0","raftState":"StatePreCandidate","applied":114,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/System/NodeLivenessMax] E240502 06:34:53.697547 8829136 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r55/1:/Table/5{3-4}] 358397 [n1,s1,r55/1:/Table/5{3-4}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r55:/Table/5{3-4} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n3,s3):2,(n2,s2):3); closed timestamp: 1714630871.518659348,0 (2024-05-02 06:21:11); raft status: {"id":"1","term":7,"vote":"2","commit":48,"lead":"0","raftState":"StatePreCandidate","applied":48,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/53] E240502 06:34:53.697948 8829137 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r38/1:/Table/3{5-6}] 358398 [n1,s1,r38/1:/Table/3{5-6}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r38:/Table/3{5-6} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630871.518659348,0 (2024-05-02 06:21:11); raft status: {"id":"1","term":7,"vote":"2","commit":42,"lead":"0","raftState":"StatePreCandidate","applied":42,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/35] E240502 06:34:53.698327 8829138 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r49/1:/Table/4{6-7}] 358399 [n1,s1,r49/1:/Table/4{6-7}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r49:/Table/4{6-7} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n2,s2):2); closed timestamp: 1714630869.678355498,0 (2024-05-02 06:21:09); raft status: {"id":"1","term":9,"vote":"2","commit":47,"lead":"0","raftState":"StatePreCandidate","applied":47,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/Table/46] E240502 06:34:53.698708 8829139 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r16/1:/Table/1{3-4}] 358400 [n1,s1,r16/1:/Table/1{3-4}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r16:/Table/1{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n2,s2):2); closed timestamp: 1714630858.310045923,0 (2024-05-02 06:20:58); raft status: {"id":"1","term":11,"vote":"1","commit":182,"lead":"0","raftState":"StatePreCandidate","applied":182,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/13] E240502 06:34:53.699092 8829140 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r17/1:/Table/1{4-5}] 358401 [n1,s1,r17/1:/Table/1{4-5}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r17:/Table/1{4-5} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630857.424347936,0 (2024-05-02 06:20:57); raft status: {"id":"1","term":9,"vote":"1","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/14] E240502 06:34:53.699487 8829141 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r26/1:/Table/2{3-4}] 358402 [n1,s1,r26/1:/Table/2{3-4}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r26:/Table/2{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n2,s2):2); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"1","term":7,"vote":"1","commit":45,"lead":"0","raftState":"StatePreCandidate","applied":45,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/23] E240502 06:34:53.699865 8829142 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r36/1:/Table/3{3-4}] 358403 [n1,s1,r36/1:/Table/3{3-4}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r36:/Table/3{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"1","term":7,"vote":"1","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 60.50s for slow proposal RequestLease [/Table/33] E240502 06:34:53.700245 8829143 kv/kvserver/queue.go:1202 [T1,Vsystem,n1,lease,s1,r50/1:/Table/4{7-8}] 358404 [n1,s1,r50/1:/Table/4{7-8}]: could not obtain lease: replica unavailable: (n1,s1):1 unable to serve request to r50:/Table/4{7-8} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n2,s2):2); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"1","term":7,"vote":"1","commit":45,"lead":"0","raftState":"StatePreCandidate","applied":45,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/47] E240502 06:34:53.702184 8829144 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r9/2:/Table/{5-6}] 358405 [n3,s3,r9/2:/Table/{5-6}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r9:/Table/{5-6} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630872.740566404,0 (2024-05-02 06:21:12); raft status: {"id":"2","term":10,"vote":"1","commit":58,"lead":"0","raftState":"StatePreCandidate","applied":58,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/5] E240502 06:34:53.702655 8829145 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicaGC,s3,r7/2:/Table/{3-4}] 358406 replica unavailable: (n3,s3):2 unable to serve request to r1:/{Min-System/NodeLiveness} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):3); closed timestamp: 1714630871.298175213,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":7,"vote":"2","commit":336,"lead":"0","raftState":"StatePreCandidate","applied":336,"progress":{},"leadtransferee":"0"}: have been waiting 62.00s for slow proposal Put [/Meta2/Table/61], [txn: 665ee49e] E240502 06:34:53.705201 8829166 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r2/2:/System/NodeLiveness{-Max}] 358407 [n2,s2,r2/2:/System/NodeLiveness{-Max}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r2:/System/NodeLiveness{-Max} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630870.834507662,0 (2024-05-02 06:21:10); raft status: {"id":"2","term":6,"vote":"0","commit":119,"lead":"0","raftState":"StatePreCandidate","applied":119,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/System/NodeLiveness] E240502 06:34:53.707043 8829177 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r41/3:/Table/3{8-9}] 358408 [n3,s3,r41/3:/Table/3{8-9}]: could not obtain lease: replica unavailable: (n3,s3):3 unable to serve request to r41:/Table/3{8-9} [(n1,s1):1, (n2,s2):2, (n3,s3):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):2); closed timestamp: 1714630871.478771401,0 (2024-05-02 06:21:11); raft status: {"id":"3","term":7,"vote":"0","commit":53,"lead":"0","raftState":"StatePreCandidate","applied":53,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/38] E240502 06:34:53.707493 8829178 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r19/2:/Table/1{6-7}] 358409 [n3,s3,r19/2:/Table/1{6-7}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r19:/Table/1{6-7} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):3); closed timestamp: 1714630875.551654980,0 (2024-05-02 06:21:15); raft status: {"id":"2","term":7,"vote":"2","commit":53,"lead":"0","raftState":"StatePreCandidate","applied":53,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/16] E240502 06:34:53.708320 8829189 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r11/2:/Table/{7-8}] 358410 [n3,s3,r11/2:/Table/{7-8}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r11:/Table/{7-8} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":8,"vote":"2","commit":44,"lead":"0","raftState":"StatePreCandidate","applied":44,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/7] E240502 06:34:53.708762 8829190 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r7/2:/Table/{3-4}] 358411 [n3,s3,r7/2:/Table/{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r7:/Table/{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630866.804846702,0 (2024-05-02 06:21:06); raft status: {"id":"2","term":7,"vote":"2","commit":47,"lead":"0","raftState":"StatePreCandidate","applied":47,"progress":{},"leadtransferee":"0"}: have been waiting 60.50s for slow proposal RequestLease [/Table/3] E240502 06:34:53.710623 8829211 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r27/2:/Table/2{4-5}] 358412 [n2,s2,r27/2:/Table/2{4-5}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r27:/Table/2{4-5} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"2","term":7,"vote":"2","commit":41,"lead":"0","raftState":"StatePreCandidate","applied":41,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/24] E240502 06:34:53.711051 8829212 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r23/2:/Table/2{0-1}] 358413 [n2,s2,r23/2:/Table/2{0-1}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r23:/Table/2{0-1} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630871.304740579,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":6,"vote":"0","commit":41,"lead":"0","raftState":"StatePreCandidate","applied":41,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/20] E240502 06:34:53.713328 8829253 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r44/2:/Table/4{1-2}] 358414 [n3,s3,r44/2:/Table/4{1-2}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r44:/Table/4{1-2} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":7,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/41] E240502 06:34:53.713794 8829254 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r5/2:/{Systemtse-Table/0}] 358415 [n3,s3,r5/2:/{Systemtse-Table/0}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r5:/{Systemtse-Table/0} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630851.031463697,0 (2024-05-02 06:20:51); raft status: {"id":"2","term":12,"vote":"2","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 60.50s for slow proposal RequestLease [/System/"tse"] E240502 06:34:53.715201 8829265 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r34/2:/{NamespaceTab…-Table/32}] 358416 [n3,s3,r34/2:/{NamespaceTab…-Table/32}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r34:/{NamespaceTable/Max-Table/32} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630857.224206291,0 (2024-05-02 06:20:57); raft status: {"id":"2","term":8,"vote":"2","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/NamespaceTable/Max] I240502 06:34:53.717223 8829209 13@kv/kvserver/allocator/allocatorimpl/allocator.go:2195 [T1,Vsystem,n2,lease,s2,r62/2:/Table/6{0-1}] 358417 expected leaseholder store to be in the slice of existing replicas E240502 06:34:53.720399 8829318 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r36/2:/Table/3{3-4}] 358418 [n3,s3,r36/2:/Table/3{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r36:/Table/3{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":7,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/33] E240502 06:34:53.720836 8829319 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r57/2:/Table/5{5-6}] 358419 [n3,s3,r57/2:/Table/5{5-6}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r57:/Table/5{5-6} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630869.076533290,0 (2024-05-02 06:21:09); raft status: {"id":"2","term":9,"vote":"1","commit":40,"lead":"0","raftState":"StatePreCandidate","applied":40,"progress":{},"leadtransferee":"0"}: have been waiting 62.00s for slow proposal RequestLease [/Table/55] E240502 06:34:53.722085 8829340 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r36/2:/Table/3{3-4}] 358420 [n3,s3,r36/2:/Table/3{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r36:/Table/3{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":7,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/33] E240502 06:34:53.723518 8829351 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r50/2:/Table/4{7-8}] 358421 [n2,s2,r50/2:/Table/4{7-8}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r50:/Table/4{7-8} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"2","term":7,"vote":"2","commit":45,"lead":"0","raftState":"StatePreCandidate","applied":45,"progress":{},"leadtransferee":"0"}: have been waiting 60.50s for slow proposal RequestLease [/Table/47] E240502 06:34:53.724824 8829352 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r32/2:/{Table/29-NamespaceTab…}] 358422 [n3,s3,r32/2:/{Table/29-NamespaceTab…}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r32:/{Table/29-NamespaceTable/30} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630873.745492719,0 (2024-05-02 06:21:13); raft status: {"id":"2","term":10,"vote":"1","commit":42,"lead":"0","raftState":"StatePreCandidate","applied":42,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/29] E240502 06:34:53.725247 8829353 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r43/2:/Table/4{0-1}] 358423 [n3,s3,r43/2:/Table/4{0-1}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r43:/Table/4{0-1} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630871.304740579,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":6,"vote":"0","commit":49,"lead":"0","raftState":"StatePreCandidate","applied":49,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/40] E240502 06:34:53.725657 8829354 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r35/2:/Table/3{2-3}] 358424 [n3,s3,r35/2:/Table/3{2-3}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r35:/Table/3{2-3} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630857.424347936,0 (2024-05-02 06:20:57); raft status: {"id":"2","term":8,"vote":"2","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/32] E240502 06:34:53.726075 8829355 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r55/2:/Table/5{3-4}] 358425 [n3,s3,r55/2:/Table/5{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r55:/Table/5{3-4} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):3); closed timestamp: 1714630871.518659348,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":7,"vote":"2","commit":48,"lead":"0","raftState":"StatePreCandidate","applied":48,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/53] E240502 06:34:53.728517 8829358 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r57/2:/Table/5{5-6}] 358426 [n3,s3,r57/2:/Table/5{5-6}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r57:/Table/5{5-6} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630869.076533290,0 (2024-05-02 06:21:09); raft status: {"id":"2","term":9,"vote":"1","commit":40,"lead":"0","raftState":"StatePreCandidate","applied":40,"progress":{},"leadtransferee":"0"}: have been waiting 62.00s for slow proposal RequestLease [/Table/55] E240502 06:34:53.728950 8829359 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r43/2:/Table/4{0-1}] 358427 [n3,s3,r43/2:/Table/4{0-1}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r43:/Table/4{0-1} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630871.304740579,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":6,"vote":"0","commit":49,"lead":"0","raftState":"StatePreCandidate","applied":49,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/40] E240502 06:34:53.729349 8829360 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r35/2:/Table/3{2-3}] 358428 [n3,s3,r35/2:/Table/3{2-3}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r35:/Table/3{2-3} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630857.424347936,0 (2024-05-02 06:20:57); raft status: {"id":"2","term":8,"vote":"2","commit":36,"lead":"0","raftState":"StatePreCandidate","applied":36,"progress":{},"leadtransferee":"0"}: have been waiting 61.00s for slow proposal RequestLease [/Table/32] E240502 06:34:53.730887 8829371 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r45/2:/Table/4{2-3}] 358429 [n2,s2,r45/2:/Table/4{2-3}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r45:/Table/4{2-3} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"2","term":8,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/Table/42] E240502 06:34:53.731749 8829392 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r46/2:/Table/4{3-4}] 358430 [n3,s3,r46/2:/Table/4{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r46:/Table/4{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":8,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/43] E240502 06:34:53.732227 8829393 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r4/2:/System{/tsd-tse}] 358431 [n3,s3,r4/2:/System{/tsd-tse}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r4:/System{/tsd-tse} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630860.708105018,0 (2024-05-02 06:21:00); raft status: {"id":"2","term":9,"vote":"1","commit":99,"lead":"0","raftState":"StatePreCandidate","applied":99,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/System/tsd] E240502 06:34:53.733303 8829404 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r46/2:/Table/4{3-4}] 358432 [n3,s3,r46/2:/Table/4{3-4}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r46:/Table/4{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630867.829180892,0 (2024-05-02 06:21:07); raft status: {"id":"2","term":8,"vote":"2","commit":39,"lead":"0","raftState":"StatePreCandidate","applied":39,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/43] E240502 06:34:53.734461 8829415 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r39/2:/Table/3{6-7}] 358433 [n2,s2,r39/2:/Table/3{6-7}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r39:/Table/3{6-7} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630871.879005623,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":8,"vote":"2","commit":43,"lead":"0","raftState":"StatePreCandidate","applied":43,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/36] E240502 06:34:53.737623 8829446 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r25/2:/Table/2{2-3}] 358434 [n3,s3,r25/2:/Table/2{2-3}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r25:/Table/2{2-3} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=4]: lost quorum (down: (n1,s1):1,(n2,s2):3); closed timestamp: 1714630871.518659348,0 (2024-05-02 06:21:11); raft status: {"id":"2","term":8,"vote":"0","commit":50,"lead":"0","raftState":"StatePreCandidate","applied":50,"progress":{},"leadtransferee":"0"}: have been waiting 62.00s for slow proposal RequestLease [/Table/22] E240502 06:34:53.738066 8829447 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,lease,s3,r52/2:/Table/5{0-1}] 358435 [n3,s3,r52/2:/Table/5{0-1}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r52:/Table/5{0-1} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630868.464415262,0 (2024-05-02 06:21:08); raft status: {"id":"2","term":8,"vote":"1","commit":41,"lead":"0","raftState":"StatePreCandidate","applied":41,"progress":{},"leadtransferee":"0"}: have been waiting 63.00s for slow proposal RequestLease [/Table/50] I240502 06:34:53.741025 2405754 sql/catalog/lease/storage.go:273 [n1,intExec=find-scheduled-jobs] 358436 retryable replica error occurred during lease acquisition for 37, retrying: replica unavailable: (n1,s1):1 unable to serve request to r7:/Table/{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n3,s3):2); closed timestamp: 1714630866.804846702,0 (2024-05-02 06:21:06); raft status: {"id":"1","term":7,"vote":"1","commit":47,"lead":"0","raftState":"StatePreCandidate","applied":47,"progress":{},"leadtransferee":"0"}: have been waiting 62.50s for slow proposal RequestLease [/Table/3] E240502 06:34:53.741552 8829498 kv/kvserver/queue.go:1202 [T1,Vsystem,n3,replicate,s3,r4/2:/System{/tsd-tse}] 358437 [n3,s3,r4/2:/System{/tsd-tse}]: could not obtain lease: replica unavailable: (n3,s3):2 unable to serve request to r4:/System{/tsd-tse} [(n1,s1):1, (n3,s3):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630860.708105018,0 (2024-05-02 06:21:00); raft status: {"id":"2","term":9,"vote":"1","commit":99,"lead":"0","raftState":"StatePreCandidate","applied":99,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/System/tsd] E240502 06:34:53.743701 8829519 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r26/2:/Table/2{3-4}] 358438 [n2,s2,r26/2:/Table/2{3-4}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r26:/Table/2{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630868.243609667,0 (2024-05-02 06:21:08); raft status: {"id":"2","term":7,"vote":"2","commit":45,"lead":"0","raftState":"StatePreCandidate","applied":45,"progress":{},"leadtransferee":"0"}: have been waiting 61.50s for slow proposal RequestLease [/Table/23] E240502 06:34:53.744152 8829520 kv/kvserver/queue.go:1202 [T1,Vsystem,n2,replicate,s2,r16/2:/Table/1{3-4}] 358439 [n2,s2,r16/2:/Table/1{3-4}]: could not obtain lease: replica unavailable: (n2,s2):2 unable to serve request to r16:/Table/1{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=2]: lost quorum (down: (n1,s1):1); closed timestamp: 1714630858.310045923,0 (2024-05-02 06:20:58); raft status: {"id":"2","term":11,"vote":"1","commit":182,"lead":"0","raftState":"StatePreCandidate","applied":182,"progress":{},"leadtransferee":"0"}: have been waiting 62.00s for slow proposal RequestLease [/Table/13] ```

Parameters:

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/obs-prs @cockroachdb/server

This test on roachdash | Improve this report!

Jira issue: CRDB-38356

dhartunian commented 2 weeks ago

Infra flake, stuck on test cluster startup.