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

storage: range lookup of meta key found only non-matching ranges #10501

Closed
petermattis opened this issue Nov 7, 2016 · 4 comments
Closed

storage: range lookup of meta key found only non-matching ranges #10501

petermattis opened this issue Nov 7, 2016 · 4 comments
Assignees
@tamird

Comments

@petermattis
Copy link
Collaborator

While investigating another bug I encountered this failure:

~ make stress PKG=./storage/ TESTS=TestStoreRangeRebalance STRESSFLAGS="-maxfails 1 -stderr -p 16"
...
I161107 08:39:05.590112 1 rand.go:76  Random seed: -3856850290110802098
I161107 08:39:05.592276 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.593988 20 gossip/gossip.go:237  [n?] initial resolvers: []
W161107 08:39:05.594027 20 gossip/gossip.go:1055  [n?] no resolvers found; use --join to specify a connected node
I161107 08:39:05.595543 20 base/node_id.go:62  NodeID set to 1
I161107 08:39:05.599768 20 storage/store.go:1174  [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available
I161107 08:39:05.599886 20 gossip/gossip.go:280  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:60233" > attrs:<> locality:<> 
I161107 08:39:05.601495 54 storage/replica_proposal.go:334  [s1,r1/1:/M{in-ax}] new range lease replica {1 1 1} 1970-01-01 00:00:00 +0000 UTC 900.000124ms following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0s [physicalTime=1970-01-01 00:00:00.000000123 +0000 UTC]
I161107 08:39:05.602020 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.603205 20 gossip/gossip.go:237  [n?] initial resolvers: [127.0.0.1:60233]
W161107 08:39:05.603233 20 gossip/gossip.go:1057  [n?] no incoming or outgoing connections
I161107 08:39:05.603269 20 base/node_id.go:62  NodeID set to 2
I161107 08:39:05.605117 20 storage/store.go:1174  [n2,s2]: failed initial metrics computation: [n2,s2]: system config not yet available
I161107 08:39:05.605161 20 gossip/gossip.go:280  [n2] NodeDescriptor set to node_id:2 address:<network_field:"tcp" address_field:"127.0.0.1:60235" > attrs:<> locality:<> 
I161107 08:39:05.605556 164 gossip/client.go:125  [n2] started gossip client to 127.0.0.1:60233
I161107 08:39:05.605800 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.607068 20 gossip/gossip.go:237  [n?] initial resolvers: [127.0.0.1:60233]
W161107 08:39:05.607097 20 gossip/gossip.go:1057  [n?] no incoming or outgoing connections
I161107 08:39:05.607170 20 base/node_id.go:62  NodeID set to 3
I161107 08:39:05.609136 20 storage/store.go:1174  [n3,s3]: failed initial metrics computation: [n3,s3]: system config not yet available
I161107 08:39:05.609176 20 gossip/gossip.go:280  [n3] NodeDescriptor set to node_id:3 address:<network_field:"tcp" address_field:"127.0.0.1:60239" > attrs:<> locality:<> 
I161107 08:39:05.609323 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.609359 172 gossip/client.go:125  [n3] started gossip client to 127.0.0.1:60233
I161107 08:39:05.610437 20 gossip/gossip.go:237  [n?] initial resolvers: [127.0.0.1:60233]
W161107 08:39:05.610457 20 gossip/gossip.go:1057  [n?] no incoming or outgoing connections
I161107 08:39:05.610503 20 base/node_id.go:62  NodeID set to 4
I161107 08:39:05.611976 20 storage/store.go:1174  [n4,s4]: failed initial metrics computation: [n4,s4]: system config not yet available
I161107 08:39:05.612016 20 gossip/gossip.go:280  [n4] NodeDescriptor set to node_id:4 address:<network_field:"tcp" address_field:"127.0.0.1:60243" > attrs:<> locality:<> 
I161107 08:39:05.614240 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.614533 252 gossip/client.go:125  [n4] started gossip client to 127.0.0.1:60233
I161107 08:39:05.615435 20 gossip/gossip.go:237  [n?] initial resolvers: [127.0.0.1:60233]
W161107 08:39:05.615454 20 gossip/gossip.go:1057  [n?] no incoming or outgoing connections
I161107 08:39:05.615489 20 base/node_id.go:62  NodeID set to 5
I161107 08:39:05.617047 20 storage/store.go:1174  [n5,s5]: failed initial metrics computation: [n5,s5]: system config not yet available
I161107 08:39:05.617087 20 gossip/gossip.go:280  [n5] NodeDescriptor set to node_id:5 address:<network_field:"tcp" address_field:"127.0.0.1:60249" > attrs:<> locality:<> 
I161107 08:39:05.617581 256 gossip/client.go:125  [n5] started gossip client to 127.0.0.1:60233
I161107 08:39:05.617726 389 gossip/server.go:263  [n1] refusing gossip from node 5 (max 3 conns); forwarding to 3 ({tcp 127.0.0.1:60239})
I161107 08:39:05.617745 20 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161107 08:39:05.618170 389 gossip/server.go:263  [n1] refusing gossip from node 5 (max 3 conns); forwarding to 2 ({tcp 127.0.0.1:60235})
I161107 08:39:05.618501 256 gossip/client.go:130  [n5] closing client to node 1 (127.0.0.1:60233): received forward from node 1 to 3 (127.0.0.1:60239)
I161107 08:39:05.618637 434 gossip/client.go:125  [n5] started gossip client to 127.0.0.1:60239
I161107 08:39:05.630058 20 gossip/gossip.go:237  [n?] initial resolvers: [127.0.0.1:60233]
W161107 08:39:05.630078 20 gossip/gossip.go:1057  [n?] no incoming or outgoing connections
I161107 08:39:05.630207 20 base/node_id.go:62  NodeID set to 6
I161107 08:39:05.650052 20 storage/store.go:1174  [n6,s6]: failed initial metrics computation: [n6,s6]: system config not yet available
I161107 08:39:05.650097 20 gossip/gossip.go:280  [n6] NodeDescriptor set to node_id:6 address:<network_field:"tcp" address_field:"127.0.0.1:60257" > attrs:<> locality:<> 
I161107 08:39:05.650206 289 gossip/client.go:125  [n6] started gossip client to 127.0.0.1:60233
I161107 08:39:05.650434 516 gossip/server.go:263  [n1] refusing gossip from node 6 (max 3 conns); forwarding to 2 ({tcp 127.0.0.1:60235})
I161107 08:39:05.650517 516 gossip/server.go:263  [n1] refusing gossip from node 6 (max 3 conns); forwarding to 3 ({tcp 127.0.0.1:60239})
I161107 08:39:05.650651 289 gossip/client.go:130  [n6] closing client to node 1 (127.0.0.1:60233): received forward from node 1 to 2 (127.0.0.1:60235)
I161107 08:39:05.650803 530 gossip/client.go:125  [n6] started gossip client to 127.0.0.1:60235
I161107 08:39:05.651764 20 storage/replica_command.go:2360  [s1,r1/1:/M{in-ax}] initiating a split of this range at key "split" [r2]
E161107 08:39:05.657036 28 storage/queue.go:579  [replicate] (purgatory) on [n1,s1,r1/1:{/Min-"split"}]: 0 of 0 stores with an attribute matching []; likely not enough nodes in cluster
I161107 08:39:05.657331 20 storage/replica_raftstorage.go:446  [s1,r1/1:{/Min-"split"}] generated snapshot b4a5bf36 for range 1 at index 21 in 40.073µs.
I161107 08:39:05.657863 20 storage/store.go:3107  streamed snapshot: kv pairs: 23, log entries: 11
E161107 08:39:05.657907 28 storage/queue.go:579  [replicate] (purgatory) on [n1,s1,r2/1:{"split"-/Max}]: 0 of 0 stores with an attribute matching []; likely not enough nodes in cluster
I161107 08:39:05.658175 458 storage/replica_raftstorage.go:592  [s2] [n2,s2,r1/?:{-}]: with replicaID [?], applying preemptive snapshot at index 21 (id=b4a5bf36, encoded size=16, 1 rocksdb batches, 11 log entries)
I161107 08:39:05.667639 458 storage/replica_raftstorage.go:595  [s2] [n2,s2,r1/?:{/Min-"split"}]: with replicaID [?], applied preemptive snapshot in 0.009s
I161107 08:39:05.670321 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:1 start_key:"" end_key:"split" replicas:<node_id:1 store_id:1 replica_id:1 > next_replica_id:2 
I161107 08:39:05.671285 597 storage/replica.go:2026  [s1,r1/1:{/Min-"split"}] proposing ADD_REPLICA {NodeID:2 StoreID:2 ReplicaID:2} for range 1: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2}]
I161107 08:39:05.672203 20 storage/replica_raftstorage.go:446  [s1,r1/1:{/Min-"split"}] generated snapshot 21686064 for range 1 at index 23 in 41.289µs.
I161107 08:39:05.672671 20 storage/store.go:3107  streamed snapshot: kv pairs: 26, log entries: 13
I161107 08:39:05.673146 565 storage/replica_raftstorage.go:592  [s3] [n3,s3,r1/?:{-}]: with replicaID [?], applying preemptive snapshot at index 23 (id=21686064, encoded size=16, 1 rocksdb batches, 13 log entries)
I161107 08:39:05.673640 565 storage/replica_raftstorage.go:595  [s3] [n3,s3,r1/?:{/Min-"split"}]: with replicaID [?], applied preemptive snapshot in 0.000s
I161107 08:39:05.674255 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:1 start_key:"" end_key:"split" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > next_replica_id:3 
I161107 08:39:05.675163 618 storage/raft_transport.go:432  raft transport stream to node 1 established
I161107 08:39:05.676780 460 storage/replica.go:2026  [s1,r1/1:{/Min-"split"}] proposing ADD_REPLICA {NodeID:3 StoreID:3 ReplicaID:3} for range 1: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2} {NodeID:3 StoreID:3 ReplicaID:3}]
I161107 08:39:05.678877 20 storage/replica_raftstorage.go:446  [s1,r2/1:{"split"-/Max}] generated snapshot 317fa458 for range 2 at index 11 in 41.853µs.
I161107 08:39:05.679559 20 storage/store.go:3107  streamed snapshot: kv pairs: 28, log entries: 1
I161107 08:39:05.680540 630 storage/replica_raftstorage.go:592  [s2] [n2,s2,r2/?:{-}]: with replicaID [?], applying preemptive snapshot at index 11 (id=317fa458, encoded size=16, 1 rocksdb batches, 1 log entries)
I161107 08:39:05.680850 630 storage/replica_raftstorage.go:595  [s2] [n2,s2,r2/?:{"split"-/Max}]: with replicaID [?], applied preemptive snapshot in 0.000s
I161107 08:39:05.681491 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:2 start_key:"split" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > next_replica_id:2 
I161107 08:39:05.683147 638 storage/raft_transport.go:432  raft transport stream to node 1 established
I161107 08:39:05.683203 480 storage/replica.go:2026  [s1,r2/1:{"split"-/Max}] proposing ADD_REPLICA {NodeID:2 StoreID:2 ReplicaID:2} for range 2: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2}]
I161107 08:39:05.684710 20 storage/replica_raftstorage.go:446  [s1,r2/1:{"split"-/Max}] generated snapshot 34a1e5cb for range 2 at index 13 in 44.599µs.
I161107 08:39:05.685407 20 storage/store.go:3107  streamed snapshot: kv pairs: 30, log entries: 3
I161107 08:39:05.686327 575 storage/replica_raftstorage.go:592  [s4] [n4,s4,r2/?:{-}]: with replicaID [?], applying preemptive snapshot at index 13 (id=34a1e5cb, encoded size=16, 1 rocksdb batches, 3 log entries)
I161107 08:39:05.686666 575 storage/replica_raftstorage.go:595  [s4] [n4,s4,r2/?:{"split"-/Max}]: with replicaID [?], applied preemptive snapshot in 0.000s
I161107 08:39:05.687098 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:2 start_key:"split" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > next_replica_id:3 
I161107 08:39:05.693663 641 storage/replica.go:2026  [s1,r2/1:{"split"-/Max}] proposing ADD_REPLICA {NodeID:4 StoreID:4 ReplicaID:3} for range 2: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2} {NodeID:4 StoreID:4 ReplicaID:3}]
I161107 08:39:05.694967 20 storage/replica_raftstorage.go:446  [s1,r2/1:{"split"-/Max}] generated snapshot 4e1b4ab6 for range 2 at index 16 in 40.155µs.
I161107 08:39:05.696304 20 storage/store.go:3107  streamed snapshot: kv pairs: 31, log entries: 6
I161107 08:39:05.697341 683 storage/raft_transport.go:432  raft transport stream to node 1 established
I161107 08:39:05.697985 663 storage/replica_raftstorage.go:592  [s5] [n5,s5,r2/?:{-}]: with replicaID [?], applying preemptive snapshot at index 16 (id=4e1b4ab6, encoded size=16, 1 rocksdb batches, 6 log entries)
I161107 08:39:05.699041 663 storage/replica_raftstorage.go:595  [s5] [n5,s5,r2/?:{"split"-/Max}]: with replicaID [?], applied preemptive snapshot in 0.001s
I161107 08:39:05.699927 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:2 start_key:"split" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > replicas:<node_id:4 store_id:4 replica_id:3 > next_replica_id:4 
I161107 08:39:05.716228 692 storage/replica.go:2026  [s1,r2/1:{"split"-/Max}] proposing ADD_REPLICA {NodeID:5 StoreID:5 ReplicaID:4} for range 2: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2} {NodeID:4 StoreID:4 ReplicaID:3} {NodeID:5 StoreID:5 ReplicaID:4}]
I161107 08:39:05.719203 20 storage/replica_command.go:3253  change replicas: read existing descriptor range_id:2 start_key:"split" end_key:"\377\377" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > replicas:<node_id:4 store_id:4 replica_id:3 > replicas:<node_id:5 store_id:5 replica_id:4 > next_replica_id:5 
I161107 08:39:05.720130 587 storage/raft_transport.go:432  raft transport stream to node 1 established
I161107 08:39:05.721502 590 storage/replica.go:2026  [s1,r2/1:{"split"-/Max}] proposing REMOVE_REPLICA {NodeID:1 StoreID:1 ReplicaID:1} for range 2: [{NodeID:5 StoreID:5 ReplicaID:4} {NodeID:2 StoreID:2 ReplicaID:2} {NodeID:4 StoreID:4 ReplicaID:3}]
E161107 08:39:05.726542 511 storage/queue.go:568  [replicate] on [n1,s1,r2/1:{"split"-/Max}]: [n1,s1,r2/1:{"split"-/Max}]: could not obtain lease: range 2 was not found
I161107 08:39:05.726578 511 storage/queue.go:630  [replicate] purgatory is now empty
W161107 08:39:05.778230 620 storage/store.go:2968  [s2] got error from range 2, replica {1 1 1}: raft group deleted
I161107 08:39:05.781735 20 storage/client_test.go:414  gossip network initialized
I161107 08:39:05.783358 20 storage/replica_raftstorage.go:446  [replicate,s1,r1/1:{/Min-"split"}] generated snapshot 7b9f8155 for range 1 at index 34 in 44.652µs.
I161107 08:39:05.783939 20 storage/store.go:3107  [replicate,s1,r1/1:{/Min-"split"}] streamed snapshot: kv pairs: 33, log entries: 24
I161107 08:39:05.784225 770 storage/replica_raftstorage.go:592  [s6] [n6,s6,r1/?:{-}]: with replicaID [?], applying preemptive snapshot at index 34 (id=7b9f8155, encoded size=16, 1 rocksdb batches, 24 log entries)
I161107 08:39:05.785058 770 storage/replica_raftstorage.go:595  [s6] [n6,s6,r1/?:{/Min-"split"}]: with replicaID [?], applied preemptive snapshot in 0.001s
I161107 08:39:05.787656 20 storage/replica_command.go:3253  [replicate,s1,r1/1:{/Min-"split"}] change replicas: read existing descriptor range_id:1 start_key:"" end_key:"split" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > replicas:<node_id:3 store_id:3 replica_id:3 > next_replica_id:4 
I161107 08:39:05.790211 701 storage/replica.go:2026  [s1,r1/1:{/Min-"split"}] proposing ADD_REPLICA {NodeID:6 StoreID:6 ReplicaID:4} for range 1: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:2 StoreID:2 ReplicaID:2} {NodeID:3 StoreID:3 ReplicaID:3} {NodeID:6 StoreID:6 ReplicaID:4}]
I161107 08:39:05.801224 20 storage/replica_command.go:3253  [replicate,s1,r1/1:{/Min-"split"}] change replicas: read existing descriptor range_id:1 start_key:"" end_key:"split" replicas:<node_id:1 store_id:1 replica_id:1 > replicas:<node_id:2 store_id:2 replica_id:2 > replicas:<node_id:3 store_id:3 replica_id:3 > replicas:<node_id:6 store_id:6 replica_id:4 > next_replica_id:5 
I161107 08:39:05.814395 792 storage/raft_transport.go:432  raft transport stream to node 1 established
I161107 08:39:05.817313 807 storage/replica.go:2026  [s1,r1/1:{/Min-"split"}] proposing REMOVE_REPLICA {NodeID:2 StoreID:2 ReplicaID:2} for range 1: [{NodeID:1 StoreID:1 ReplicaID:1} {NodeID:6 StoreID:6 ReplicaID:4} {NodeID:3 StoreID:3 ReplicaID:3}]
I161107 08:39:05.823343 620 storage/store.go:2964  [s2] [n2,s2,r1/2:{/Min-"split"}]: added to replica GC queue (peer suggestion)
F161107 08:39:05.826435 773 storage/replica_command.go:1121  [s2,r1/2:{/Min-"split"}] range lookup of meta key /Meta2/System/NodeLiveness/2 found only non-matching ranges: []
goroutine 773 [running]:
github.com/cockroachdb/cockroach/pkg/util/log.getStacks(0x300, 0xc43142670b, 0x5f953e0, 0x0)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:849 +0xa5
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).outputLogEntry(0x5f96a80, 0xc400000004, 0x5b5807c, 0x1a, 0x461, 0xc420c34b00, 0x71)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:710 +0x7ca
github.com/cockroachdb/cockroach/pkg/util/log.addStructured(0x8a22878, 0xc420cf05a0, 0xc400000004, 0x2, 0x5405eb4, 0x3f, 0xc420e1c688, 0x2, 0x2)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/log/structured.go:140 +0x296
github.com/cockroachdb/cockroach/pkg/util/log.logDepth(0x8a22878, 0xc420cf05a0, 0x1, 0xc400000004, 0x5405eb4, 0x3f, 0xc420e1c688, 0x2, 0x2)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:88 +0x8c
github.com/cockroachdb/cockroach/pkg/util/log.Fatalf(0x8a22878, 0xc420cf05a0, 0x5405eb4, 0x3f, 0xc420e1c688, 0x2, 0x2)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:172 +0x7e
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).RangeLookup(0xc4201cf180, 0x8a22878, 0xc420cf05a0, 0x5c25940, 0xc42024f770, 0x6b49d27d, 0x2e, 0x200000002, 0x2, 0x1, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_command.go:1121 +0xe23
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).executeCmd(0xc4201cf180, 0x8a22878, 0xc420cf05a0, 0x0, 0x0, 0x0, 0x5c25940, 0xc42024f770, 0x0, 0x6b49d27d, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_command.go:135 +0x29f
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).executeBatch(0xc4201cf180, 0x8a22878, 0xc420cf05a0, 0x0, 0x0, 0x5c25940, 0xc42024f770, 0x0, 0x6b49d27d, 0x2e, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:3639 +0x426
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).addReadOnlyCmd(0xc4201cf180, 0x8a22878, 0xc420cf05a0, 0x6b49d27d, 0x2e, 0x200000002, 0x2, 0x1, 0x0, 0x0, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:1579 +0x26c
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).Send(0xc4201cf180, 0x8a22878, 0xc420cf05a0, 0x6b49d27d, 0x2e, 0x200000002, 0x2, 0x1, 0x0, 0x0, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:1116 +0x48f
github.com/cockroachdb/cockroach/pkg/storage.(*Store).Send(0xc420174e00, 0x8a22878, 0xc420cf0540, 0x6b49d27d, 0x2e, 0x200000002, 0x2, 0x1, 0x0, 0x0, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:2354 +0x75e
github.com/cockroachdb/cockroach/pkg/storage.(*Stores).Send(0xc42065b140, 0x8a22800, 0xc4209a4140, 0x0, 0x0, 0x200000002, 0x2, 0x1, 0x0, 0x0, ...)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/stores.go:187 +0x202
github.com/cockroachdb/cockroach/pkg/storage_test.(*multiTestContextKVTransport).SendNext.func1(0x8a22800, 0xc4209a4140)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/storage/client_test.go:471 +0x136
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTask.func1(0xc42053ac60, 0x5b56a9d, 0x16, 0x1f5, 0x0, 0x0, 0xc420660340, 0x8a22800, 0xc4209a4140)
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:264 +0xdf
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunAsyncTask
	/Users/pmattis/Development/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:265 +0x234


ERROR: exit status 255

219 runs completed, 1 failures, over 9s

That error was introduced in dfcf5fd.
@petermattis
Copy link
Collaborator Author

I've reproduced it 3 times now, always within 20-30s using the above make stress command.

@petermattis petermattis mentioned this issue Nov 7, 2016
Merged
@tamird
Copy link
Contributor

tamird commented Nov 7, 2016

Trying to reproduce this locally I hit:

--- FAIL: TestStoreRangeRebalance (13.35s)
    client_raft_test.go:2160: expected 0 normal snapshots, but found 1
FAIL


ERROR: exit status 1

14 runs completed, 1 failures, over 21s

Which is #10156.

@petermattis petermattis mentioned this issue Nov 7, 2016
Merged
@tamird
Copy link
Contributor

tamird commented Nov 7, 2016

This reproduces with make stress PKG=./pkg/storage TESTS=TestRaftRemoveRace STRESSFLAGS='-maxfails 1 -stderr -p 16'. Investigating.

@petermattis
Copy link
Collaborator Author

And it goes away if you disable node liveness heartbeats via stopNodeLivenessHeartbeats(mtc). I needed that to make progress on #10497.

@tamird tamird closed this as completed in 87b419f Nov 10, 2016
@bdarnell bdarnell mentioned this issue Jun 1, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@tamird tamird

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@tamird @petermattis