search

cockroachdb / cockroach

CockroachDB — the cloud native, distributed SQL database designed for high availability, effortless scale, and control over data placement.
https://www.cockroachlabs.com
Other
29.86k stars 3.77k forks source link

teamcity: failed tests on master: testrace/TestAmbiguousCommit/ambiguousSuccess=true, testrace/TestAmbiguousCommit, testrace/TestAmbiguousCommit/ambiguousSuccess=false #17740

Closed cockroach-teamcity closed 7 years ago

cockroach-teamcity commented 7 years ago

The following tests appear to have failed:

#327369:

--- FAIL: testrace/TestAmbiguousCommit/ambiguousSuccess=true (0.000s)
Test ended in panic.

------- Stdout: -------
W170817 19:46:23.192388 50254 server/status/runtime.go:109  Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I170817 19:46:23.214136 50254 server/config.go:534  [n?] 1 storage engine initialized
I170817 19:46:23.215655 50254 server/config.go:536  [n?] RocksDB cache size: 512 MiB
I170817 19:46:23.215707 50254 server/config.go:536  [n?] store 0: in-memory, size 100 MiB
I170817 19:46:23.269200 50254 server/node.go:345  [n?] **** cluster a8ebc13d-a982-4165-96a8-195c2bf7b3d1 has been created
I170817 19:46:23.269306 50254 server/server.go:785  [n?] **** add additional nodes by specifying --join=127.0.0.1:59812
I170817 19:46:23.281867 50254 storage/store.go:1189  [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available
I170817 19:46:23.282120 50254 server/node.go:462  [n1] initialized store [n1,s1]: diskUsed=0 B/512 MiB (0.00%), ranges=1, leases=0, writes=0.00, bytesPerReplica={p10=3266.00 p25=3266.00 p50=3266.00 p75=3266.00 p90=3266.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00}
I170817 19:46:23.321799 50254 server/node.go:327  [n1] node ID 1 initialized
I170817 19:46:23.322254 50254 gossip/gossip.go:295  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:59812" > attrs:<> locality:<> ServerVersion:<major_val:1 minor_val:0 patch:0 unstable:3 > 
I170817 19:46:23.323150 50254 storage/stores.go:303  [n1] read 0 node addresses from persistent storage
I170817 19:46:23.323641 50254 server/node.go:603  [n1] connecting to gossip network to verify cluster ID...
I170817 19:46:23.323829 50254 server/node.go:628  [n1] node connected via gossip and verified as part of cluster "a8ebc13d-a982-4165-96a8-195c2bf7b3d1"
I170817 19:46:23.324182 50254 server/node.go:404  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I170817 19:46:23.343297 50389 storage/replica_command.go:2703  [split,n1,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I170817 19:46:23.344017 50254 sql/executor.go:373  [n1] creating distSQLPlanner with address {tcp 127.0.0.1:59812}
E170817 19:46:23.443240 50390 storage/queue.go:656  [replicate,n1,s1,r1/1:/{Min-System/}] range requires a replication change, but lacks a quorum of live replicas (0/1)
I170817 19:46:23.447416 50389 storage/replica_command.go:2703  [split,n1,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/tsd [r3]
I170817 19:46:23.475728 50254 server/server.go:877  [n1] starting https server at 127.0.0.1:38809
I170817 19:46:23.475846 50254 server/server.go:878  [n1] starting grpc/postgres server at 127.0.0.1:59812
I170817 19:46:23.475898 50254 server/server.go:879  [n1] advertising CockroachDB node at 127.0.0.1:59812
W170817 19:46:23.498564 50254 sql/jobs/registry.go:156  [n1] unable to get node liveness: node not in the liveness table
I170817 19:46:23.574363 50389 storage/replica_command.go:2703  [split,n1,s1,r3/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r4]
I170817 19:46:23.646771 50254 sql/event_log.go:102  [n1] Event: "alter_table", target: 12, info: {TableName:eventlog Statement:ALTER TABLE system.eventlog ALTER COLUMN "uniqueID" SET DEFAULT uuid_v4() User:node MutationID:0 CascadeDroppedViews:[]}
E170817 19:46:23.698521 50434 storage/replica_proposal.go:538  [n1,s1,r3/1:/{System/tsd-Max}] could not load SystemConfig span: must retry later due to intent on SystemConfigSpan
I170817 19:46:23.737003 50389 storage/replica_command.go:2703  [split,n1,s1,r4/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r5]
I170817 19:46:23.778302 50254 sql/lease.go:341  [n1] publish: descID=12 (eventlog) version=2 mtime=2017-08-17 19:46:23.773242228 +0000 UTC
I170817 19:46:23.839128 50389 storage/replica_command.go:2703  [split,n1,s1,r5/1:/{Table/System���-Max}] initiating a split of this range at key /Table/11 [r6]
I170817 19:46:23.901907 50389 storage/replica_command.go:2703  [split,n1,s1,r6/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r7]
I170817 19:46:23.984033 50389 storage/replica_command.go:2703  [split,n1,s1,r7/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r8]
I170817 19:46:24.061398 50254 sql/event_log.go:102  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:node}
I170817 19:46:24.121263 50389 storage/replica_command.go:2703  [split,n1,s1,r8/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r9]
I170817 19:46:24.237591 50389 storage/replica_command.go:2703  [split,n1,s1,r9/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r10]
I170817 19:46:24.313774 50254 sql/event_log.go:102  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:
                    User:node}
I170817 19:46:24.326619 50254 server/server.go:1021  [n1] done ensuring all necessary migrations have run
I170817 19:46:24.326746 50254 server/server.go:1023  [n1] serving sql connections
I170817 19:46:24.354452 50389 storage/replica_command.go:2703  [split,n1,s1,r10/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r11]
I170817 19:46:24.396065 50866 sql/event_log.go:102  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:59812} Attrs: Locality: ServerVersion:1.0-3} ClusterID:a8ebc13d-a982-4165-96a8-195c2bf7b3d1 StartedAt:1502999183323901460 LastUp:1502999183323901460}
I170817 19:46:24.527110 50389 storage/replica_command.go:2703  [split,n1,s1,r11/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r12]
I170817 19:46:24.686911 50389 storage/replica_command.go:2703  [split,n1,s1,r12/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r13]
I170817 19:46:24.796855 50389 storage/replica_command.go:2703  [split,n1,s1,r13/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r14]
W170817 19:46:25.141226 50254 server/status/runtime.go:109  Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
W170817 19:46:25.147445 50254 gossip/gossip.go:1209  [n?] no incoming or outgoing connections
I170817 19:46:25.166250 50254 server/config.go:534  [n?] 1 storage engine initialized
I170817 19:46:25.166373 50254 server/config.go:536  [n?] RocksDB cache size: 512 MiB
I170817 19:46:25.166433 50254 server/config.go:536  [n?] store 0: in-memory, size 100 MiB
I170817 19:46:25.166632 50254 server/server.go:787  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I170817 19:46:25.253485 51052 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:59812
I170817 19:46:25.287078 50984 gossip/server.go:232  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:57059}
I170817 19:46:25.316667 50254 storage/stores.go:303  [n?] read 0 node addresses from persistent storage
I170817 19:46:25.322418 50254 storage/stores.go:322  [n?] wrote 1 node addresses to persistent storage
I170817 19:46:25.322934 50254 server/node.go:603  [n?] connecting to gossip network to verify cluster ID...
I170817 19:46:25.323275 50254 server/node.go:628  [n?] node connected via gossip and verified as part of cluster "a8ebc13d-a982-4165-96a8-195c2bf7b3d1"
I170817 19:46:25.361123 50254 kv/dist_sender.go:359  [n?] unable to determine this node's attributes for replica selection; node is most likely bootstrapping
I170817 19:46:25.365953 50254 server/node.go:320  [n?] new node allocated ID 2
I170817 19:46:25.366260 50254 gossip/gossip.go:295  [n2] NodeDescriptor set to node_id:2 address:<network_field:"tcp" address_field:"127.0.0.1:57059" > attrs:<> locality:<> ServerVersion:<major_val:1 minor_val:0 patch:0 unstable:3 > 
I170817 19:46:25.366712 50254 server/node.go:390  [n2] node=2: asynchronously bootstrapping engine(s) [<no-attributes>=<in-mem>]
I170817 19:46:25.367036 50254 server/node.go:404  [n2] node=2: started with [] engine(s) and attributes []
I170817 19:46:25.391617 51096 storage/stores.go:322  [n1] wrote 1 node addresses to persistent storage
I170817 19:46:25.393194 50254 sql/executor.go:373  [n2] creating distSQLPlanner with address {tcp 127.0.0.1:57059}
I170817 19:46:25.449872 50254 server/server.go:877  [n2] starting https server at 127.0.0.1:59567
I170817 19:46:25.450995 50254 server/server.go:878  [n2] starting grpc/postgres server at 127.0.0.1:57059
I170817 19:46:25.451046 50254 server/server.go:879  [n2] advertising CockroachDB node at 127.0.0.1:57059
W170817 19:46:25.451456 50254 sql/jobs/registry.go:156  [n2] unable to get node liveness: node not in the liveness table
I170817 19:46:25.472352 50254 server/server.go:1021  [n2] done ensuring all necessary migrations have run
I170817 19:46:25.472486 50254 server/server.go:1023  [n2] serving sql connections
I170817 19:46:25.510198 51109 server/node.go:584  [n2] bootstrapped store [n2,s2]
I170817 19:46:25.685790 51267 sql/event_log.go:102  [n2] Event: "node_join", target: 2, info: {Descriptor:{NodeID:2 Address:{NetworkField:tcp AddressField:127.0.0.1:57059} Attrs: Locality: ServerVersion:1.0-3} ClusterID:a8ebc13d-a982-4165-96a8-195c2bf7b3d1 StartedAt:1502999185366849360 LastUp:1502999185366849360}
W170817 19:46:25.754354 50254 server/status/runtime.go:109  Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
W170817 19:46:25.767277 50254 gossip/gossip.go:1209  [n?] no incoming or outgoing connections
I170817 19:46:25.799377 50254 server/config.go:534  [n?] 1 storage engine initialized
I170817 19:46:25.799533 50254 server/config.go:536  [n?] RocksDB cache size: 512 MiB
I170817 19:46:25.799632 50254 server/config.go:536  [n?] store 0: in-memory, size 100 MiB
I170817 19:46:25.799866 50254 server/server.go:787  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I170817 19:46:25.957714 51277 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:59812
I170817 19:46:25.967507 51071 gossip/server.go:232  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:33473}
I170817 19:46:25.976032 50254 storage/stores.go:303  [n?] read 0 node addresses from persistent storage
I170817 19:46:25.976276 50254 storage/stores.go:322  [n?] wrote 2 node addresses to persistent storage
I170817 19:46:25.976316 50254 server/node.go:603  [n?] connecting to gossip network to verify cluster ID...
I170817 19:46:25.976415 50254 server/node.go:628  [n?] node connected via gossip and verified as part of cluster "a8ebc13d-a982-4165-96a8-195c2bf7b3d1"
I170817 19:46:25.986955 50254 kv/dist_sender.go:359  [n?] unable to determine this node's attributes for replica selection; node is most likely bootstrapping
I170817 19:46:25.992207 50254 server/node.go:320  [n?] new node allocated ID 3
I170817 19:46:25.992548 50254 gossip/gossip.go:295  [n3] NodeDescriptor set to node_id:3 address:<network_field:"tcp" address_field:"127.0.0.1:33473" > attrs:<> locality:<> ServerVersion:<major_val:1 minor_val:0 patch:0 unstable:3 > 
I170817 19:46:25.995100 51286 storage/stores.go:322  [n1] wrote 2 node addresses to persistent storage
I170817 19:46:25.999236 51350 storage/stores.go:322  [n2] wrote 2 node addresses to persistent storage
I170817 19:46:26.000543 50254 server/node.go:390  [n3] node=3: asynchronously bootstrapping engine(s) [<no-attributes>=<in-mem>]
I170817 19:46:26.001491 50254 server/node.go:404  [n3] node=3: started with [] engine(s) and attributes []
I170817 19:46:26.040504 51363 server/node.go:584  [n3] bootstrapped store [n3,s3]
I170817 19:46:26.044997 50254 sql/executor.go:373  [n3] creating distSQLPlanner with address {tcp 127.0.0.1:33473}
I170817 19:46:26.139196 50254 server/server.go:877  [n3] starting https server at 127.0.0.1:40082
I170817 19:46:26.139320 50254 server/server.go:878  [n3] starting grpc/postgres server at 127.0.0.1:33473
I170817 19:46:26.139364 50254 server/server.go:879  [n3] advertising CockroachDB node at 127.0.0.1:33473
W170817 19:46:26.139660 50254 sql/jobs/registry.go:156  [n3] unable to get node liveness: node not in the liveness table
I170817 19:46:26.155794 50254 server/server.go:1021  [n3] done ensuring all necessary migrations have run
I170817 19:46:26.155979 50254 server/server.go:1023  [n3] serving sql connections
I170817 19:46:26.161998 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r7/1:/Table/1{2-3}] generated preemptive snapshot 951f236c at index 26
I170817 19:46:26.298813 51289 sql/event_log.go:102  [n3] Event: "node_join", target: 3, info: {Descriptor:{NodeID:3 Address:{NetworkField:tcp AddressField:127.0.0.1:33473} Attrs: Locality: ServerVersion:1.0-3} ClusterID:a8ebc13d-a982-4165-96a8-195c2bf7b3d1 StartedAt:1502999186001209273 LastUp:1502999186001209273}
I170817 19:46:26.338984 50501 storage/store.go:3449  [replicate,n1,s1,r7/1:/Table/1{2-3}] streamed snapshot to (n3,s3):?: kv pairs: 36, log entries: 16, rate-limit: 8.0 MiB/sec, 6ms
I170817 19:46:26.340347 51518 storage/replica_raftstorage.go:718  [n3,s3,r7/?:{-}] applying preemptive snapshot at index 26 (id=951f236c, encoded size=18161, 1 rocksdb batches, 16 log entries)
I170817 19:46:26.342046 51518 storage/replica_raftstorage.go:726  [n3,s3,r7/?:/Table/1{2-3}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I170817 19:46:26.349327 50501 storage/replica_command.go:3636  [replicate,n1,s1,r7/1:/Table/1{2-3}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r7:/Table/1{2-3} [(n1,s1):1, next=2]
I170817 19:46:26.372382 51456 storage/replica.go:2999  [n1,s1,r7/1:/Table/1{2-3}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:26.376912 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r10/1:/Table/1{5-6}] generated preemptive snapshot 753c67e4 at index 21
I170817 19:46:26.410482 51542 storage/raft_transport.go:455  [n3] raft transport stream to node 1 established
I170817 19:46:26.511399 50390 storage/store.go:3449  [replicate,n1,s1,r10/1:/Table/1{5-6}] streamed snapshot to (n2,s2):?: kv pairs: 11, log entries: 11, rate-limit: 8.0 MiB/sec, 5ms
I170817 19:46:26.512704 51605 storage/replica_raftstorage.go:718  [n2,s2,r10/?:{-}] applying preemptive snapshot at index 21 (id=753c67e4, encoded size=6752, 1 rocksdb batches, 11 log entries)
I170817 19:46:26.514169 51605 storage/replica_raftstorage.go:726  [n2,s2,r10/?:/Table/1{5-6}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:26.518839 50390 storage/replica_command.go:3636  [replicate,n1,s1,r10/1:/Table/1{5-6}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r10:/Table/1{5-6} [(n1,s1):1, next=2]
I170817 19:46:26.553677 51592 storage/replica.go:2999  [n1,s1,r10/1:/Table/1{5-6}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:26.577838 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r8/1:/Table/1{3-4}] generated preemptive snapshot 0bdaaba3 at index 33
I170817 19:46:26.596182 50501 storage/store.go:3449  [replicate,n1,s1,r8/1:/Table/1{3-4}] streamed snapshot to (n2,s2):?: kv pairs: 103, log entries: 23, rate-limit: 8.0 MiB/sec, 17ms
I170817 19:46:26.599844 51580 storage/replica_raftstorage.go:718  [n2,s2,r8/?:{-}] applying preemptive snapshot at index 33 (id=0bdaaba3, encoded size=37448, 1 rocksdb batches, 23 log entries)
I170817 19:46:26.601451 51581 storage/raft_transport.go:455  [n2] raft transport stream to node 1 established
I170817 19:46:26.647883 51580 storage/replica_raftstorage.go:726  [n2,s2,r8/?:/Table/1{3-4}] applied preemptive snapshot in 47ms [clear=0ms batch=0ms entries=1ms commit=24ms]
I170817 19:46:26.655971 50501 storage/replica_command.go:3636  [replicate,n1,s1,r8/1:/Table/1{3-4}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r8:/Table/1{3-4} [(n1,s1):1, next=2]
I170817 19:46:26.697918 51624 storage/replica.go:2999  [n1,s1,r8/1:/Table/1{3-4}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:26.703109 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r2/1:/System/{-tsd}] generated preemptive snapshot d2c39ddb at index 44
I170817 19:46:26.708104 50390 storage/store.go:3449  [replicate,n1,s1,r2/1:/System/{-tsd}] streamed snapshot to (n3,s3):?: kv pairs: 37, log entries: 3, rate-limit: 8.0 MiB/sec, 4ms
I170817 19:46:26.710456 51642 storage/replica_raftstorage.go:718  [n3,s3,r2/?:{-}] applying preemptive snapshot at index 44 (id=d2c39ddb, encoded size=81556, 1 rocksdb batches, 3 log entries)
I170817 19:46:26.723681 51642 storage/replica_raftstorage.go:726  [n3,s3,r2/?:/System/{-tsd}] applied preemptive snapshot in 13ms [clear=0ms batch=0ms entries=0ms commit=12ms]
I170817 19:46:26.728430 50390 storage/replica_command.go:3636  [replicate,n1,s1,r2/1:/System/{-tsd}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r2:/System/{-tsd} [(n1,s1):1, next=2]
I170817 19:46:26.773995 51615 storage/replica.go:2999  [n1,s1,r2/1:/System/{-tsd}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:26.783196 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r13/1:/Table/1{8-9}] generated preemptive snapshot a77b2508 at index 19
I170817 19:46:26.787855 50501 storage/store.go:3449  [replicate,n1,s1,r13/1:/Table/1{8-9}] streamed snapshot to (n3,s3):?: kv pairs: 10, log entries: 9, rate-limit: 8.0 MiB/sec, 3ms
I170817 19:46:26.789429 51617 storage/replica_raftstorage.go:718  [n3,s3,r13/?:{-}] applying preemptive snapshot at index 19 (id=a77b2508, encoded size=5799, 1 rocksdb batches, 9 log entries)
I170817 19:46:26.790781 51617 storage/replica_raftstorage.go:726  [n3,s3,r13/?:/Table/1{8-9}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:26.806427 50501 storage/replica_command.go:3636  [replicate,n1,s1,r13/1:/Table/1{8-9}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r13:/Table/1{8-9} [(n1,s1):1, next=2]
I170817 19:46:26.846080 51563 storage/replica.go:2999  [n1,s1,r13/1:/Table/1{8-9}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:26.856113 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] generated preemptive snapshot d1934d37 at index 33
I170817 19:46:26.862103 51699 storage/replica_raftstorage.go:718  [n2,s2,r5/?:{-}] applying preemptive snapshot at index 33 (id=d1934d37, encoded size=24433, 1 rocksdb batches, 23 log entries)
I170817 19:46:26.864921 50390 storage/store.go:3449  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] streamed snapshot to (n2,s2):?: kv pairs: 44, log entries: 23, rate-limit: 8.0 MiB/sec, 5ms
I170817 19:46:26.866405 51699 storage/replica_raftstorage.go:726  [n2,s2,r5/?:/Table/{SystemCon���-11}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I170817 19:46:26.876166 50390 storage/replica_command.go:3636  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r5:/Table/{SystemConfigSpan/Start-11} [(n1,s1):1, next=2]
I170817 19:46:26.923027 51717 storage/replica.go:2999  [n1,s1,r5/1:/Table/{SystemCon���-11}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:26.931208 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] generated preemptive snapshot 43040fd6 at index 35
I170817 19:46:26.954219 50501 storage/store.go:3449  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] streamed snapshot to (n3,s3):?: kv pairs: 46, log entries: 25, rate-limit: 8.0 MiB/sec, 22ms
I170817 19:46:26.972243 51719 storage/replica_raftstorage.go:718  [n3,s3,r5/?:{-}] applying preemptive snapshot at index 35 (id=43040fd6, encoded size=26382, 1 rocksdb batches, 25 log entries)
I170817 19:46:26.983931 51719 storage/replica_raftstorage.go:726  [n3,s3,r5/?:/Table/{SystemCon���-11}] applied preemptive snapshot in 11ms [clear=0ms batch=0ms entries=9ms commit=2ms]
I170817 19:46:26.988388 50501 storage/replica_command.go:3636  [replicate,n1,s1,r5/1:/Table/{SystemCon���-11}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r5:/Table/{SystemConfigSpan/Start-11} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:27.025183 51644 storage/replica.go:2999  [n1,s1,r5/1:/Table/{SystemCon���-11}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:27.038658 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r1/1:/{Min-System/}] generated preemptive snapshot 85184d46 at index 68
I170817 19:46:27.090814 50501 storage/store.go:3449  [replicate,n1,s1,r1/1:/{Min-System/}] streamed snapshot to (n2,s2):?: kv pairs: 47, log entries: 58, rate-limit: 8.0 MiB/sec, 51ms
I170817 19:46:27.093111 51721 storage/replica_raftstorage.go:718  [n2,s2,r1/?:{-}] applying preemptive snapshot at index 68 (id=85184d46, encoded size=32941, 1 rocksdb batches, 58 log entries)
I170817 19:46:27.116669 51721 storage/replica_raftstorage.go:726  [n2,s2,r1/?:/{Min-System/}] applied preemptive snapshot in 23ms [clear=0ms batch=0ms entries=22ms commit=0ms]
I170817 19:46:27.120805 50501 storage/replica_command.go:3636  [replicate,n1,s1,r1/1:/{Min-System/}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r1:/{Min-System/} [(n1,s1):1, next=2]
I170817 19:46:27.157718 51739 storage/replica.go:2999  [n1,s1,r1/1:/{Min-System/}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:27.175036 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r3/1:/System/ts{d-e}] generated preemptive snapshot 387c6a36 at index 28
I170817 19:46:27.211498 51744 storage/replica_raftstorage.go:718  [n3,s3,r3/?:{-}] applying preemptive snapshot at index 28 (id=387c6a36, encoded size=157027, 1 rocksdb batches, 2 log entries)
I170817 19:46:27.217433 51744 storage/replica_raftstorage.go:726  [n3,s3,r3/?:/System/ts{d-e}] applied preemptive snapshot in 6ms [clear=0ms batch=2ms entries=1ms commit=1ms]
I170817 19:46:27.218988 50390 storage/store.go:3449  [replicate,n1,s1,r3/1:/System/ts{d-e}] streamed snapshot to (n3,s3):?: kv pairs: 1076, log entries: 2, rate-limit: 8.0 MiB/sec, 43ms
I170817 19:46:27.222824 50390 storage/replica_command.go:3636  [replicate,n1,s1,r3/1:/System/ts{d-e}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r3:/System/ts{d-e} [(n1,s1):1, next=2]
I170817 19:46:27.259219 51810 storage/replica.go:2999  [n1,s1,r3/1:/System/ts{d-e}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:27.273223 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r11/1:/Table/1{6-7}] generated preemptive snapshot 2c97ef2a at index 21
I170817 19:46:27.277320 50501 storage/store.go:3449  [replicate,n1,s1,r11/1:/Table/1{6-7}] streamed snapshot to (n2,s2):?: kv pairs: 11, log entries: 11, rate-limit: 8.0 MiB/sec, 3ms
I170817 19:46:27.280732 51785 storage/replica_raftstorage.go:718  [n2,s2,r11/?:{-}] applying preemptive snapshot at index 21 (id=2c97ef2a, encoded size=6756, 1 rocksdb batches, 11 log entries)
I170817 19:46:27.297419 51785 storage/replica_raftstorage.go:726  [n2,s2,r11/?:/Table/1{6-7}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:27.306820 50501 storage/replica_command.go:3636  [replicate,n1,s1,r11/1:/Table/1{6-7}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r11:/Table/1{6-7} [(n1,s1):1, next=2]
I170817 19:46:27.350297 51788 storage/replica.go:2999  [n1,s1,r11/1:/Table/1{6-7}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:27.357868 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] generated preemptive snapshot ec9f304c at index 23
I170817 19:46:27.369219 50501 storage/store.go:3449  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 13, rate-limit: 8.0 MiB/sec, 10ms
I170817 19:46:27.373292 51792 storage/replica_raftstorage.go:718  [n2,s2,r4/?:{-}] applying preemptive snapshot at index 23 (id=ec9f304c, encoded size=9316, 1 rocksdb batches, 13 log entries)
I170817 19:46:27.393019 51792 storage/replica_raftstorage.go:726  [n2,s2,r4/?:/{System/tse-Table/System���}] applied preemptive snapshot in 19ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:27.402648 50501 storage/replica_command.go:3636  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r4:/{System/tse-Table/SystemConfigSpan/Start} [(n1,s1):1, next=2]
I170817 19:46:27.445052 51828 storage/replica.go:2999  [n1,s1,r4/1:/{System/tse-Table/System���}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:27.451937 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r14/1:/{Table/19-Max}] generated preemptive snapshot 250fbbc8 at index 11
I170817 19:46:27.461836 50501 storage/store.go:3449  [replicate,n1,s1,r14/1:/{Table/19-Max}] streamed snapshot to (n3,s3):?: kv pairs: 9, log entries: 1, rate-limit: 8.0 MiB/sec, 9ms
I170817 19:46:27.519553 51803 storage/replica_raftstorage.go:718  [n3,s3,r14/?:{-}] applying preemptive snapshot at index 11 (id=250fbbc8, encoded size=547, 1 rocksdb batches, 1 log entries)
I170817 19:46:27.520911 51803 storage/replica_raftstorage.go:726  [n3,s3,r14/?:/{Table/19-Max}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:27.542872 50501 storage/replica_command.go:3636  [replicate,n1,s1,r14/1:/{Table/19-Max}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r14:/{Table/19-Max} [(n1,s1):1, next=2]
I170817 19:46:27.684676 51757 storage/replica.go:2999  [n1,s1,r14/1:/{Table/19-Max}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:27.690973 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r9/1:/Table/1{4-5}] generated preemptive snapshot 9b4c0d6d at index 18
I170817 19:46:27.695477 50501 storage/store.go:3449  [replicate,n1,s1,r9/1:/Table/1{4-5}] streamed snapshot to (n2,s2):?: kv pairs: 11, log entries: 8, rate-limit: 8.0 MiB/sec, 4ms
I170817 19:46:27.699743 51774 storage/replica_raftstorage.go:718  [n2,s2,r9/?:{-}] applying preemptive snapshot at index 18 (id=9b4c0d6d, encoded size=5075, 1 rocksdb batches, 8 log entries)
I170817 19:46:27.708843 51774 storage/replica_raftstorage.go:726  [n2,s2,r9/?:/Table/1{4-5}] applied preemptive snapshot in 9ms [clear=0ms batch=0ms entries=0ms commit=8ms]
I170817 19:46:27.730406 50501 storage/replica_command.go:3636  [replicate,n1,s1,r9/1:/Table/1{4-5}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r9:/Table/1{4-5} [(n1,s1):1, next=2]
I170817 19:46:27.792562 51890 storage/replica.go:2999  [n1,s1,r9/1:/Table/1{4-5}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I170817 19:46:27.796682 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r2/1:/System/{-tsd}] generated preemptive snapshot b5119eea at index 47
I170817 19:46:27.805561 50501 storage/store.go:3449  [replicate,n1,s1,r2/1:/System/{-tsd}] streamed snapshot to (n2,s2):?: kv pairs: 38, log entries: 6, rate-limit: 8.0 MiB/sec, 4ms
I170817 19:46:27.810251 51907 storage/replica_raftstorage.go:718  [n2,s2,r2/?:{-}] applying preemptive snapshot at index 47 (id=b5119eea, encoded size=83599, 1 rocksdb batches, 6 log entries)
I170817 19:46:27.815548 51907 storage/replica_raftstorage.go:726  [n2,s2,r2/?:/System/{-tsd}] applied preemptive snapshot in 5ms [clear=0ms batch=0ms entries=1ms commit=4ms]
I170817 19:46:27.829618 50501 storage/replica_command.go:3636  [replicate,n1,s1,r2/1:/System/{-tsd}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r2:/System/{-tsd} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:27.899123 51938 storage/replica.go:2999  [n1,s1,r2/1:/System/{-tsd}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:27.917349 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r3/1:/System/ts{d-e}] generated preemptive snapshot 70479195 at index 31
I170817 19:46:27.960513 50501 storage/store.go:3449  [replicate,n1,s1,r3/1:/System/ts{d-e}] streamed snapshot to (n2,s2):?: kv pairs: 1077, log entries: 5, rate-limit: 8.0 MiB/sec, 39ms
I170817 19:46:27.962286 51861 storage/replica_raftstorage.go:718  [n2,s2,r3/?:{-}] applying preemptive snapshot at index 31 (id=70479195, encoded size=159127, 1 rocksdb batches, 5 log entries)
I170817 19:46:27.965372 51861 storage/replica_raftstorage.go:726  [n2,s2,r3/?:/System/ts{d-e}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=1ms]
I170817 19:46:28.043869 50501 storage/replica_command.go:3636  [replicate,n1,s1,r3/1:/System/ts{d-e}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r3:/System/ts{d-e} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:28.172715 51836 storage/replica.go:2999  [n1,s1,r3/1:/System/ts{d-e}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:28.182952 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r10/1:/Table/1{5-6}] generated preemptive snapshot 6b36c1d6 at index 24
I170817 19:46:28.191577 50501 storage/store.go:3449  [replicate,n1,s1,r10/1:/Table/1{5-6}] streamed snapshot to (n3,s3):?: kv pairs: 12, log entries: 14, rate-limit: 8.0 MiB/sec, 5ms
I170817 19:46:28.193450 51958 storage/replica_raftstorage.go:718  [n3,s3,r10/?:{-}] applying preemptive snapshot at index 24 (id=6b36c1d6, encoded size=8783, 1 rocksdb batches, 14 log entries)
I170817 19:46:28.194847 51958 storage/replica_raftstorage.go:726  [n3,s3,r10/?:/Table/1{5-6}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.201787 50501 storage/replica_command.go:3636  [replicate,n1,s1,r10/1:/Table/1{5-6}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r10:/Table/1{5-6} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:28.258646 51872 storage/replica.go:2999  [n1,s1,r10/1:/Table/1{5-6}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:28.266941 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r6/1:/Table/1{1-2}] generated preemptive snapshot a98bde56 at index 18
I170817 19:46:28.270472 50501 storage/store.go:3449  [replicate,n1,s1,r6/1:/Table/1{1-2}] streamed snapshot to (n3,s3):?: kv pairs: 11, log entries: 8, rate-limit: 8.0 MiB/sec, 3ms
I170817 19:46:28.272923 51928 storage/replica_raftstorage.go:718  [n3,s3,r6/?:{-}] applying preemptive snapshot at index 18 (id=a98bde56, encoded size=6329, 1 rocksdb batches, 8 log entries)
I170817 19:46:28.275320 51928 storage/replica_raftstorage.go:726  [n3,s3,r6/?:/Table/1{1-2}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.278972 50501 storage/replica_command.go:3636  [replicate,n1,s1,r6/1:/Table/1{1-2}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r6:/Table/1{1-2} [(n1,s1):1, next=2]
I170817 19:46:28.338104 51990 storage/replica.go:2999  [n1,s1,r6/1:/Table/1{1-2}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:28.344595 50501 storage/replica_raftstorage.go:509  [replicate,n1,s1,r12/1:/Table/1{7-8}] generated preemptive snapshot 39f2cb22 at index 21
I170817 19:46:28.347779 50501 storage/store.go:3449  [replicate,n1,s1,r12/1:/Table/1{7-8}] streamed snapshot to (n3,s3):?: kv pairs: 11, log entries: 11, rate-limit: 8.0 MiB/sec, 2ms
I170817 19:46:28.349608 51977 storage/replica_raftstorage.go:718  [n3,s3,r12/?:{-}] applying preemptive snapshot at index 21 (id=39f2cb22, encoded size=6756, 1 rocksdb batches, 11 log entries)
I170817 19:46:28.350992 51977 storage/replica_raftstorage.go:726  [n3,s3,r12/?:/Table/1{7-8}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.359631 50501 storage/replica_command.go:3636  [replicate,n1,s1,r12/1:/Table/1{7-8}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r12:/Table/1{7-8} [(n1,s1):1, next=2]
I170817 19:46:28.440282 51888 storage/replica.go:2999  [n1,s1,r12/1:/Table/1{7-8}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I170817 19:46:28.449058 50501 storage/queue.go:723  [n1,replicate] purgatory is now empty
I170817 19:46:28.450389 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r11/1:/Table/1{6-7}] generated preemptive snapshot b7021b49 at index 24
I170817 19:46:28.466812 50390 storage/store.go:3449  [replicate,n1,s1,r11/1:/Table/1{6-7}] streamed snapshot to (n3,s3):?: kv pairs: 12, log entries: 14, rate-limit: 8.0 MiB/sec, 15ms
I170817 19:46:28.468420 52034 storage/replica_raftstorage.go:718  [n3,s3,r11/?:{-}] applying preemptive snapshot at index 24 (id=b7021b49, encoded size=8787, 1 rocksdb batches, 14 log entries)
I170817 19:46:28.470199 52034 storage/replica_raftstorage.go:726  [n3,s3,r11/?:/Table/1{6-7}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.480119 50390 storage/replica_command.go:3636  [replicate,n1,s1,r11/1:/Table/1{6-7}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r11:/Table/1{6-7} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:28.531608 51985 storage/replica.go:2999  [n1,s1,r11/1:/Table/1{6-7}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:28.557205 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r12/1:/Table/1{7-8}] generated preemptive snapshot 75817e10 at index 24
I170817 19:46:28.579221 50390 storage/store.go:3449  [replicate,n1,s1,r12/1:/Table/1{7-8}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 14, rate-limit: 8.0 MiB/sec, 21ms
I170817 19:46:28.585431 52067 storage/replica_raftstorage.go:718  [n2,s2,r12/?:{-}] applying preemptive snapshot at index 24 (id=75817e10, encoded size=8787, 1 rocksdb batches, 14 log entries)
I170817 19:46:28.594258 52067 storage/replica_raftstorage.go:726  [n2,s2,r12/?:/Table/1{7-8}] applied preemptive snapshot in 5ms [clear=0ms batch=0ms entries=4ms commit=0ms]
I170817 19:46:28.678308 50390 storage/replica_command.go:3636  [replicate,n1,s1,r12/1:/Table/1{7-8}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r12:/Table/1{7-8} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:28.733312 52071 storage/replica.go:2999  [n1,s1,r12/1:/Table/1{7-8}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:28.747692 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r14/1:/{Table/19-Max}] generated preemptive snapshot 53d8bdc7 at index 16
I170817 19:46:28.752696 50390 storage/store.go:3449  [replicate,n1,s1,r14/1:/{Table/19-Max}] streamed snapshot to (n2,s2):?: kv pairs: 11, log entries: 6, rate-limit: 8.0 MiB/sec, 4ms
I170817 19:46:28.754540 52045 storage/replica_raftstorage.go:718  [n2,s2,r14/?:{-}] applying preemptive snapshot at index 16 (id=53d8bdc7, encoded size=3541, 1 rocksdb batches, 6 log entries)
I170817 19:46:28.755911 52045 storage/replica_raftstorage.go:726  [n2,s2,r14/?:/{Table/19-Max}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.759604 50390 storage/replica_command.go:3636  [replicate,n1,s1,r14/1:/{Table/19-Max}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r14:/{Table/19-Max} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:28.834165 52055 storage/replica.go:2999  [n1,s1,r14/1:/{Table/19-Max}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:28.849845 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r6/1:/Table/1{1-2}] generated preemptive snapshot cb69063c at index 21
I170817 19:46:28.862402 50390 storage/store.go:3449  [replicate,n1,s1,r6/1:/Table/1{1-2}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 11, rate-limit: 8.0 MiB/sec, 12ms
I170817 19:46:28.870076 52130 storage/replica_raftstorage.go:718  [n2,s2,r6/?:{-}] applying preemptive snapshot at index 21 (id=cb69063c, encoded size=8360, 1 rocksdb batches, 11 log entries)
I170817 19:46:28.872179 52130 storage/replica_raftstorage.go:726  [n2,s2,r6/?:/Table/1{1-2}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=0ms commit=1ms]
I170817 19:46:28.879054 50390 storage/replica_command.go:3636  [replicate,n1,s1,r6/1:/Table/1{1-2}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r6:/Table/1{1-2} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:28.918978 52059 storage/replica.go:2999  [n1,s1,r6/1:/Table/1{1-2}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:28.942473 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r9/1:/Table/1{4-5}] generated preemptive snapshot 0a8a4ef9 at index 21
I170817 19:46:28.944421 51426 storage/replica_proposal.go:453  [n3,s3,r12/2:/Table/1{7-8}] new range lease repl=(n3,s3):2 start=1502999188.929849809,0 epo=1 pro=1502999188.929858409,0 following repl=(n1,s1):1 start=0.000000000,0 exp=1502999192.282372572,0 pro=1502999183.282431572,0
I170817 19:46:28.952932 50390 storage/store.go:3449  [replicate,n1,s1,r9/1:/Table/1{4-5}] streamed snapshot to (n3,s3):?: kv pairs: 12, log entries: 11, rate-limit: 8.0 MiB/sec, 10ms
I170817 19:46:28.959001 52017 storage/replica_raftstorage.go:718  [n3,s3,r9/?:{-}] applying preemptive snapshot at index 21 (id=0a8a4ef9, encoded size=7106, 1 rocksdb batches, 11 log entries)
I170817 19:46:28.961538 52017 storage/replica_raftstorage.go:726  [n3,s3,r9/?:/Table/1{4-5}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:28.982654 50390 storage/replica_command.go:3636  [replicate,n1,s1,r9/1:/Table/1{4-5}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r9:/Table/1{4-5} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:29.038384 52063 storage/replica.go:2999  [n1,s1,r9/1:/Table/1{4-5}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:29.064718 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] generated preemptive snapshot 32165ab3 at index 26
I170817 19:46:29.070668 52182 storage/replica_raftstorage.go:718  [n3,s3,r4/?:{-}] applying preemptive snapshot at index 26 (id=32165ab3, encoded size=11404, 1 rocksdb batches, 16 log entries)
I170817 19:46:29.072640 52182 storage/replica_raftstorage.go:726  [n3,s3,r4/?:/{System/tse-Table/System���}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I170817 19:46:29.086803 50390 storage/store.go:3449  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] streamed snapshot to (n3,s3):?: kv pairs: 13, log entries: 16, rate-limit: 8.0 MiB/sec, 21ms
I170817 19:46:29.093108 50390 storage/replica_command.go:3636  [replicate,n1,s1,r4/1:/{System/tse-Table/System���}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r4:/{System/tse-Table/SystemConfigSpan/Start} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:29.155662 52195 storage/replica.go:2999  [n1,s1,r4/1:/{System/tse-Table/System���}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:29.167906 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r8/1:/Table/1{3-4}] generated preemptive snapshot af4f3ee6 at index 82
I170817 19:46:29.178305 50390 storage/store.go:3449  [replicate,n1,s1,r8/1:/Table/1{3-4}] streamed snapshot to (n3,s3):?: kv pairs: 215, log entries: 12, rate-limit: 8.0 MiB/sec, 8ms
I170817 19:46:29.181132 52173 storage/replica_raftstorage.go:718  [n3,s3,r8/?:{-}] applying preemptive snapshot at index 82 (id=af4f3ee6, encoded size=33388, 1 rocksdb batches, 12 log entries)
I170817 19:46:29.182893 52173 storage/replica_raftstorage.go:726  [n3,s3,r8/?:/Table/1{3-4}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:29.186114 50390 storage/replica_command.go:3636  [replicate,n1,s1,r8/1:/Table/1{3-4}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r8:/Table/1{3-4} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:29.192367 52061 storage/raft_transport.go:455  [n3] raft transport stream to node 2 established
I170817 19:46:29.272901 52124 storage/replica.go:2999  [n1,s1,r8/1:/Table/1{3-4}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:29.306330 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r1/1:/{Min-System/}] generated preemptive snapshot 24e69bd9 at index 106
I170817 19:46:29.321899 50390 storage/store.go:3449  [replicate,n1,s1,r1/1:/{Min-System/}] streamed snapshot to (n3,s3):?: kv pairs: 67, log entries: 96, rate-limit: 8.0 MiB/sec, 13ms
I170817 19:46:29.324901 52244 storage/replica_raftstorage.go:718  [n3,s3,r1/?:{-}] applying preemptive snapshot at index 106 (id=24e69bd9, encoded size=52625, 1 rocksdb batches, 96 log entries)
I170817 19:46:29.380351 52244 storage/replica_raftstorage.go:726  [n3,s3,r1/?:/{Min-System/}] applied preemptive snapshot in 54ms [clear=0ms batch=0ms entries=51ms commit=0ms]
I170817 19:46:29.386622 50390 storage/replica_command.go:3636  [replicate,n1,s1,r1/1:/{Min-System/}] change replicas (ADD_REPLICA (n3,s3):3): read existing descriptor r1:/{Min-System/} [(n1,s1):1, (n2,s2):2, next=3]
I170817 19:46:29.425662 52154 storage/raft_transport.go:455  [n2] raft transport stream to node 3 established
I170817 19:46:29.452725 52261 storage/replica.go:2999  [n1,s1,r1/1:/{Min-System/}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):1 (n2,s2):2 (n3,s3):3] next=4
I170817 19:46:29.485846 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r13/1:/Table/1{8-9}] generated preemptive snapshot 8895ac5e at index 24
I170817 19:46:29.489879 50390 storage/store.go:3449  [replicate,n1,s1,r13/1:/Table/1{8-9}] streamed snapshot to (n2,s2):?: kv pairs: 12, log entries: 14, rate-limit: 8.0 MiB/sec, 3ms
I170817 19:46:29.496299 52225 storage/replica_raftstorage.go:718  [n2,s2,r13/?:{-}] applying preemptive snapshot at index 24 (id=8895ac5e, encoded size=8787, 1 rocksdb batches, 14 log entries)
I170817 19:46:29.497767 52225 storage/replica_raftstorage.go:726  [n2,s2,r13/?:/Table/1{8-9}] applied preemptive snapshot in 1ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I170817 19:46:29.501146 50390 storage/replica_command.go:3636  [replicate,n1,s1,r13/1:/Table/1{8-9}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r13:/Table/1{8-9} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:29.556287 52295 storage/replica.go:2999  [n1,s1,r13/1:/Table/1{8-9}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:29.573034 50390 storage/replica_raftstorage.go:509  [replicate,n1,s1,r7/1:/Table/1{2-3}] generated preemptive snapshot b563733f at index 31
I170817 19:46:29.602873 50390 storage/store.go:3449  [replicate,n1,s1,r7/1:/Table/1{2-3}] streamed snapshot to (n2,s2):?: kv pairs: 42, log entries: 21, rate-limit: 8.0 MiB/sec, 29ms
I170817 19:46:29.604566 52204 storage/replica_raftstorage.go:718  [n2,s2,r7/?:{-}] applying preemptive snapshot at index 31 (id=b563733f, encoded size=23478, 1 rocksdb batches, 21 log entries)
I170817 19:46:29.627439 52204 storage/replica_raftstorage.go:726  [n2,s2,r7/?:/Table/1{2-3}] applied preemptive snapshot in 23ms [clear=0ms batch=0ms entries=8ms commit=8ms]
I170817 19:46:29.630599 50390 storage/replica_command.go:3636  [replicate,n1,s1,r7/1:/Table/1{2-3}] change replicas (ADD_REPLICA (n2,s2):3): read existing descriptor r7:/Table/1{2-3} [(n1,s1):1, (n3,s3):2, next=3]
I170817 19:46:29.667341 52249 storage/replica.go:2999  [n1,s1,r7/1:/Table/1{2-3}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I170817 19:46:30.081668 52193 sql/event_log.go:102  [client=127.0.0.1:41494,user=root,n1] Event: "create_database", target: 50, info: {DatabaseName:test Statement:CREATE DATABASE test User:root}
I170817 19:46:30.089390 50389 storage/replica_command.go:2703  [split,n1,s1,r14/1:/{Table/19-Max}] initiating a split of this range at key /Table/50 [r15]
I170817 19:46:30.192416 51386 storage/replica_proposal.go:453  [n3,s3,r9/3:/Table/1{4-5}] new range lease repl=(n3,s3):3 start=1502999190.115960559,0 epo=1 pro=1502999190.118960258,0 following repl=(n1,s1):1 start=0.000000000,0 exp=1502999192.282372572,0 pro=1502999183.282431572,0
I170817 19:46:30.310287 52193 sql/event_log.go:102  [client=127.0.0.1:41494,user=root,n1] Event: "create_table", target: 51, info: {TableName:test.t Statement:CREATE TABLE test.t (k SERIAL PRIMARY KEY, v INT) User:root}
I170817 19:46:30.361127 50389 storage/replica_command.go:2703  [split,n1,s1,r15/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r16]
I170817 19:46:30.717334 52443 util/stop/stopper.go:475  quiescing; tasks left:
1      node.Node: batch
1      [async] gossip.infoStore: callback
I170817 19:46:30.719105 52443 util/stop/stopper.go:475  quiescing; tasks left:
1      [async] gossip.infoStore: callback
W170817 19:46:30.719191 51596 storage/raft_transport.go:461  [n1] raft transport stream to node 2 failed: rpc error: code = Unavailable desc = transport is closing
I170817 19:46:30.723183 51315 vendor/google.golang.org/grpc/grpclog/grpclog.go:75  transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:59812->127.0.0.1:41477: use of closed network connection
W170817 19:46:30.725483 52061 storage/raft_transport.go:461  [n3] raft transport stream to node 2 failed: EOF
W170817 19:46:30.726232 51542 storage/raft_transport.go:461  [n3] raft transport stream to node 1 failed: rpc error: code = Unavailable desc = transport is closing
E170817 19:46:30.728371 51450 util/log/crash_reporting.go:82  [n3] a panic has occurred!
I170817 19:46:30.730738 50273 kv/transport_race.go:69  transport race promotion: ran 27 iterations on up to 835 requests
W170817 19:46:30.730851 51529 storage/raft_transport.go:461  [n1] raft transport stream to node 3 failed: rpc error: code = Unavailable desc = transport is closing
W170817 19:46:30.731072 51581 storage/raft_transport.go:461  [n2] raft transport stream to node 1 failed: rpc error: code = Unavailable desc = transport is closing
W170817 19:46:30.735096 52154 storage/raft_transport.go:461  [n2] raft transport stream to node 3 failed: EOF
--- FAIL: testrace/TestAmbiguousCommit (0.000s)
Test ended in panic.

--- FAIL: testrace/TestAmbiguousCommit/ambiguousSuccess=false (0.000s)
Test ended in panic.

------- Stdout: -------
E170817 19:46:30.773038 51450 util/log/crash_reporting.go:183  [n3] Reported as error d07838b7337540529f509831a746708f
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1dfb48b]

goroutine 51450 [running]:
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).Recover(0xc4237b9440, 0x7f4dae1a1260, 0xc42161aa50)
    /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:182 +0x105
panic(0x21cdb60, 0x32c2240)
    /usr/local/go/src/runtime/panic.go:489 +0x2f0
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).divideAndSendBatchToRanges.func1(0xc423af2028, 0xc423af27a8, 0xc423af27a0, 0xc423af1f2a, 0xc423af2700, 0xc423af2010)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:672 +0x510
panic(0x21cdb60, 0x32c2240)
    /usr/local/go/src/runtime/panic.go:489 +0x2f0
github.com/cockroachdb/cockroach/pkg/sql_test.TestAmbiguousCommit.func1.2.1(0x7f4dae1a6c78, 0xc423935a00, 0xc420dcec60)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/ambiguous_commit_test.go:97 +0x17b
github.com/cockroachdb/cockroach/pkg/sql_test.(*interceptingTransport).SendNext(0xc420346220, 0x7f4dae1a6c78, 0xc423935a00, 0xc420dcec60)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/ambiguous_commit_test.go:47 +0x71
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendToReplicas(0xc4221d0000, 0x7f4dae1a6c78, 0xc423935a00, 0xc4221d0048, 0x2, 0xc420346020, 0x1, 0x1, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:1144 +0x6b3
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendRPC(0xc4221d0000, 0x7f4dae1a6c78, 0xc423935a00, 0x2, 0xc420346020, 0x1, 0x1, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:391 +0x353
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendSingleRange(0xc4221d0000, 0x7f4dae1a1260, 0xc420846c90, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc4231289a0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:455 +0x1b8
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendPartialBatch(0xc4221d0000, 0x7f4dae1a1260, 0xc420846c90, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc4231289a0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:939 +0x575
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).divideAndSendBatchToRanges(0xc4221d0000, 0x7f4dae1a1260, 0xc420846c90, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc4231289a0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:804 +0xd1e
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).Send(0xc4221d0000, 0x7f4dae1a1260, 0xc420846c90, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc4231287e0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:606 +0x3ee
github.com/cockroachdb/cockroach/pkg/kv.(*TxnCoordSender).Send(0xc420ff4620, 0x7f4dae1a1260, 0xc420846ba0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc423128700, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/kv/txn_coord_sender.go:435 +0x282
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).send(0xc42038f220, 0x7f4dae1a6c78, 0xc4239358c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc423128700, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:554 +0x20a
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Send(0xc4204d6000, 0x7f4dae1a6c78, 0xc4239358c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:908 +0x5c3
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Send-fm(0x7f4dae1a6c78, 0xc4239358c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:486 +0xa4
github.com/cockroachdb/cockroach/pkg/internal/client.sendAndFill(0x7f4dae1a6c78, 0xc4239358c0, 0xc420a43548, 0xc4232c2300, 0xc420f9f9d0, 0xc420a43670)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:463 +0x156
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Run(0xc4204d6000, 0x7f4dae1a6c78, 0xc4239358c0, 0xc4232c2300, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:486 +0x112
github.com/cockroachdb/cockroach/pkg/storage.(*NodeLiveness).updateLiveness.func1(0x7f4dae1a6c78, 0xc4239358c0, 0xc4204d6000, 0x2, 0x2236ee0)
    /go/src/github.com/cockroachdb/cockroach/pkg/storage/node_liveness.go:634 +0x599
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).Txn.func1(0x7f4dae1a6c78, 0xc4239358c0, 0xc4204d6000, 0xc4203f8036, 0xc41ff16070, 0x2)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:516 +0x5f
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Exec(0xc4204d6000, 0x7f4dae1a6c78, 0xc4239358c0, 0xc423930101, 0xc4203f8100, 0xc420846a20, 0xc421013db0)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:722 +0xc6
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).Txn(0xc42038f220, 0x7f4dae1a6c78, 0xc4239358c0, 0xc421013da0, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:517 +0x175
github.com/cockroachdb/cockroach/pkg/storage.(*NodeLiveness).updateLiveness(0xc420068c00, 0x7f4dae1a1260, 0xc4208469f0, 0xc420846a80, 0xc420846a20, 0xc422a4bb70, 0x37a2340, 0xc420a43af0)
    /go/src/github.com/cockroachdb/cockroach/pkg/storage/node_liveness.go:635 +0x18d
github.com/cockroachdb/cockroach/pkg/storage.(*NodeLiveness).heartbeatInternal.func1(0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/storage/node_liveness.go:421 +0x4f2
github.com/cockroachdb/cockroach/pkg/storage.(*NodeLiveness).heartbeatInternal(0xc420068c00, 0x7f4dae1a1260, 0xc4208469f0, 0xc420846a20, 0x4000000000000000, 0x0, 0x3fc3333333333333)
    /go/src/github.com/cockroachdb/cockroach/pkg/storage/node_liveness.go:437 +0x130
github.com/cockroachdb/cockroach/pkg/storage.(*NodeLiveness).StartHeartbeat.func1(0x7f4dae1a1260, 0xc42161aa50)
    /go/src/github.com/cockroachdb/cockroach/pkg/storage/node_liveness.go:320 +0x599
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4202f80b0, 0xc4237b9440, 0xc42120a000)
    /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:197 +0x161
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
    /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:198 +0xbb

goroutine 1 [chan receive]:
testing.(*T).Run(0xc42007cb60, 0x23b35dd, 0x13, 0x247a738, 0xc420501b01)
    /usr/local/go/src/testing/testing.go:698 +0x582
testing.runTests.func1(0xc42007cb60)
    /usr/local/go/src/testing/testing.go:882 +0xab
testing.tRunner(0xc42007cb60, 0xc420501d10)
    /usr/local/go/src/testing/testing.go:657 +0x108
testing.runTests(0xc4203f0ca0, 0x32dde40, 0xae, 0xae, 0x302e93b)
    /usr/local/go/src/testing/testing.go:888 +0x4e1
testing.(*M).Run(0xc42083df28, 0x4165fa0)
    /usr/local/go/src/testing/testing.go:822 +0x1c4
github.com/cockroachdb/cockroach/pkg/sql_test.TestMain(0xc420501f28)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/main_test.go:221 +0x18a
main.main()
    github.com/cockroachdb/cockroach/pkg/sql/_test/_testmain.go:414 +0x210

goroutine 17 [syscall, 2 minutes, locked to thread]:
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:2197 +0x1

goroutine 20 [chan receive]:
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).flushDaemon(0x37a3f20)
    /go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:990 +0x85
created by github.com/cockroachdb/cockroach/pkg/util/log.init.1
    /go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:575 +0x13a

goroutine 21 [syscall, 2 minutes]:
os/signal.signal_recv(0x7046c1)
    /usr/local/go/src/runtime/sigqueue.go:116 +0x104
os/signal.loop()
    /usr/local/go/src/os/signal/signal_unix.go:22 +0x30
created by os/signal.init.1
    /usr/local/go/src/os/signal/signal_unix.go:28 +0x4f

goroutine 507 [select, locked to thread]:
runtime.gopark(0x247ce18, 0x0, 0x239f4a2, 0x6, 0x18, 0x2)
    /usr/local/go/src/runtime/proc.go:271 +0xfd
runtime.selectgoImpl(0xc420462750, 0xc420462738, 0x0)
    /usr/local/go/src/runtime/select.go:423 +0x138a
runtime.selectgo(0xc420462750)
    /usr/local/go/src/runtime/select.go:238 +0x1c
runtime.ensureSigM.func1()
    /usr/local/go/src/runtime/signal_unix.go:434 +0x1ea
runtime.goexit()
    /usr/local/go/src/runtime/asm_amd64.s:2197 +0x1

goroutine 52519 [chan receive]:
github.com/cockroachdb/cockroach/vendor/github.com/getsentry/raven-go.(*Client).worker(0xc42041fc00)
    /go/src/github.com/cockroachdb/cockroach/vendor/github.com/getsentry/raven-go/client.go:482 +0x94
created by github.com/cockroachdb/cockroach/vendor/github.com/getsentry/raven-go.(*Client).Capture.func1
    /go/src/github.com/cockroachdb/cockroach/vendor/github.com/getsentry/raven-go/client.go:541 +0x56

goroutine 52417 [runnable]:
compress/flate.(*decompressor).huffSym(0xc423093900, 0xc423093928, 0x55, 0x0, 0x0)
    /usr/local/go/src/compress/flate/inflate.go:707 +0x4d5
compress/flate.(*decompressor).huffmanBlock(0xc423093900)
    /usr/local/go/src/compress/flate/inflate.go:493 +0xac
compress/flate.(*decompressor).nextBlock(0xc423093900)
    /usr/local/go/src/compress/flate/inflate.go:326 +0x355
compress/flate.(*decompressor).Read(0xc423093900, 0xc421b34a00, 0x200, 0x200, 0x0, 0x0, 0x0)
    /usr/local/go/src/compress/flate/inflate.go:346 +0xd8
compress/gzip.(*Reader).Read(0xc420680580, 0xc421b34a00, 0x200, 0x200, 0x0, 0x0, 0x1)
    /usr/local/go/src/compress/gzip/gunzip.go:251 +0xc9
bytes.(*Buffer).ReadFrom(0xc42122cc40, 0x32e4fa0, 0xc420680580, 0x7f4dae1a6b00, 0xc42122cc40, 0x1)
    /usr/local/go/src/bytes/buffer.go:179 +0x1bd
io.copyBuffer(0x32e4ea0, 0xc42122cc40, 0x32e4fa0, 0xc420680580, 0x0, 0x0, 0x0, 0xc424a41310, 0x6b5338, 0x70)
    /usr/local/go/src/io/io.go:384 +0x35b
io.Copy(0x32e4ea0, 0xc42122cc40, 0x32e4fa0, 0xc420680580, 0x0, 0x7f4dae19d810, 0x0)
    /usr/local/go/src/io/io.go:360 +0x7f
github.com/cockroachdb/cockroach/pkg/security/securitytest.bindataRead(0x331ab20, 0x35c, 0x35c, 0x23c07d6, 0x1a, 0x5c, 0xffffffffffffffff, 0x1a, 0x1a, 0x2)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/securitytest/embedded.go:34 +0x35a
github.com/cockroachdb/cockroach/pkg/security/securitytest.test_certsClientRootCrtBytes(0x199b424, 0x6d4a05, 0xc424a414e8, 0x8, 0xc424a414f0)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/securitytest/embedded.go:124 +0x82
github.com/cockroachdb/cockroach/pkg/security/securitytest.test_certsClientRootCrt(0xc4202287e0, 0xc4203707e0, 0xc420357820)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/securitytest/embedded.go:128 +0x45
github.com/cockroachdb/cockroach/pkg/security/securitytest.AssetInfo(0xc420357820, 0x1a, 0x2, 0xc420357820, 0x1a, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/securitytest/embedded.go:270 +0x124
github.com/cockroachdb/cockroach/pkg/security/securitytest.AssetReadDir(0x23a57bf, 0xa, 0xc4200b6850, 0xc4200b7030, 0xc422ed4070, 0xc422ed4930, 0xc422ed5dc0)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/securitytest/securitytest.go:63 +0x34d
github.com/cockroachdb/cockroach/pkg/security.(*CertificateLoader).Load(0xc424a41be8, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/security/certificate_loader.go:203 +0x8e
github.com/cockroachdb/cockroach/pkg/security.(*CertificateManager).LoadCertificates(0xc42122c7e0, 0x0, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/sec

Please assign, take a look and update the issue accordingly.

knz commented 7 years ago

@andreimatei please triage

knz commented 7 years ago

Dup #17726