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
30.06k stars 3.8k forks source link

teamcity: failed tests on master: testrace/TestMultiNodeExportStmt, test/TestSystemZoneConfigs, testrace/TestSystemZoneConfigs, test/TestMultiNodeExportStmt #30325

Closed cockroach-teamcity closed 6 years ago

cockroach-teamcity commented 6 years ago

The following tests appear to have failed:

#910024:

--- FAIL: testrace/TestMultiNodeExportStmt (0.000s)
Test ended in panic.

------- Stdout: -------
W180917 20:21:17.795845 72670 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180917 20:21:17.846357 72670 server/server.go:847  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180917 20:21:17.847175 72670 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:17.847315 72670 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:17.870421 72670 server/config.go:493  [n?] 1 storage engine initialized
I180917 20:21:17.871820 72670 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180917 20:21:17.871923 72670 server/config.go:496  [n?] store 0: in-memory, size 0 B
I180917 20:21:17.955071 72670 util/stop/stopper.go:537  [n?] quiescing; tasks left:
1      [async] storage.pendingLeaseRequest: requesting lease
I180917 20:21:17.974521 72670 server/node.go:374  [n?] **** cluster 7453afb9-0b32-433a-bb9d-6282b83b63ca has been created
I180917 20:21:17.974688 72670 server/server.go:1411  [n?] **** add additional nodes by specifying --join=127.0.0.1:37383
I180917 20:21:17.975890 72670 gossip/gossip.go:408  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:37383" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-881-g7be4709" started_at:1537215677975469043 
I180917 20:21:17.995524 72774 gossip/gossip.go:940  [n1] gossip connectivity
I180917 20:21:18.010367 72670 server/node.go:477  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=7.0 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7183.00 p25=7183.00 p50=7183.00 p75=7183.00 p90=7183.00 pMax=7183.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I180917 20:21:18.010893 72670 storage/stores.go:242  [n1] read 0 node addresses from persistent storage
I180917 20:21:18.011385 72670 server/node.go:700  [n1] connecting to gossip network to verify cluster ID...
I180917 20:21:18.052372 72670 server/node.go:725  [n1] node connected via gossip and verified as part of cluster "7453afb9-0b32-433a-bb9d-6282b83b63ca"
I180917 20:21:18.052905 72670 server/node.go:549  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180917 20:21:18.056402 72670 server/status/recorder.go:611  [n1] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180917 20:21:18.056582 72670 server/server.go:1802  [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180917 20:21:18.066532 72670 server/server.go:1548  [n1] starting https server at 127.0.0.1:34521 (use: 127.0.0.1:34521)
I180917 20:21:18.066721 72670 server/server.go:1550  [n1] starting grpc/postgres server at 127.0.0.1:37383
I180917 20:21:18.066799 72670 server/server.go:1551  [n1] advertising CockroachDB node at 127.0.0.1:37383
W180917 20:21:18.067214 72670 jobs/registry.go:309  [n1] unable to get node liveness: node not in the liveness table
I180917 20:21:18.116998 72677 storage/replica_command.go:298  [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180917 20:21:18.481953 72794 storage/replica_command.go:298  [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
W180917 20:21:18.520372 72948 storage/intent_resolver.go:668  [n1,s1] failed to push during intent resolution: failed to push "unnamed" id=4d6586b6 key=/Table/SystemConfigSpan/Start rw=true pri=0.00062557 iso=SERIALIZABLE stat=PENDING epo=0 ts=1537215678.126270694,0 orig=1537215678.126270694,0 max=1537215678.126270694,0 wto=false rop=false seq=6
I180917 20:21:18.592051 72680 sql/event_log.go:126  [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I180917 20:21:18.633988 72950 storage/replica_command.go:298  [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
I180917 20:21:18.805507 72930 storage/replica_command.go:298  [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180917 20:21:18.927922 72983 storage/replica_command.go:298  [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
I180917 20:21:19.098532 72683 sql/event_log.go:126  [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.0-13 User:root}
I180917 20:21:19.124018 72594 storage/replica_command.go:298  [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180917 20:21:19.222396 72987 rpc/nodedialer/nodedialer.go:92  [n1,consistencyChecker,s1,r1/1:/{Min-System/}] connection to n1 established
I180917 20:21:19.293028 72688 sql/event_log.go:126  [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root}
I180917 20:21:19.320455 73005 storage/replica_command.go:298  [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
I180917 20:21:19.438697 72961 storage/replica_command.go:298  [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180917 20:21:19.563885 73014 storage/replica_command.go:298  [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180917 20:21:19.655763 73065 storage/replica_command.go:298  [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180917 20:21:19.728032 73061 sql/event_log.go:126  [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:d02519f9-fd94-4396-b978-52a4b78f0f9d User:root}
I180917 20:21:19.763823 73100 storage/replica_command.go:298  [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180917 20:21:19.872600 73018 storage/replica_command.go:298  [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180917 20:21:19.874045 72774 gossip/gossip.go:940  [n1] gossip connectivity
  n1 [sentinel];
I180917 20:21:19.976728 73108 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root}
I180917 20:21:20.019836 73038 storage/replica_command.go:298  [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180917 20:21:20.075004 73037 sql/event_log.go:126  [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root}
I180917 20:21:20.186666 73111 storage/replica_command.go:298  [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180917 20:21:20.197556 72670 server/server.go:1604  [n1] done ensuring all necessary migrations have run
I180917 20:21:20.197755 72670 server/server.go:1607  [n1] serving sql connections
I180917 20:21:20.245549 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.246379 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.247310 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.249128 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.260141 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.260936 73114 sql/event_log.go:126  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:37383} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-881-g7be4709 StartedAt:1537215677975469043 LocalityAddress:[]} ClusterID:7453afb9-0b32-433a-bb9d-6282b83b63ca StartedAt:1537215677975469043 LastUp:1537215677975469043}
I180917 20:21:20.263798 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.268876 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.270084 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.271126 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.272008 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.273236 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.274221 73112 server/server_update.go:67  [n1] no need to upgrade, cluster already at the newest version
I180917 20:21:20.277092 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.277717 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.278240 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.278791 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.279412 72670 server/testserver.go:446  had 14 ranges at startup, expected 22
I180917 20:21:20.308693 73132 storage/replica_command.go:298  [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180917 20:21:20.314196 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.318234 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.319412 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.320587 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.332654 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.343130 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.348884 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.354362 72670 server/testserver.go:446  had 15 ranges at startup, expected 22
I180917 20:21:20.403657 73136 storage/replica_command.go:298  [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180917 20:21:20.404888 72670 server/testserver.go:446  had 16 ranges at startup, expected 22
I180917 20:21:20.431580 72670 server/testserver.go:446  had 16 ranges at startup, expected 22
I180917 20:21:20.494046 73191 storage/replica_command.go:298  [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180917 20:21:20.503894 72670 server/testserver.go:446  had 17 ranges at startup, expected 22
I180917 20:21:20.559966 73120 storage/replica_command.go:298  [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180917 20:21:20.578779 72670 server/testserver.go:446  had 18 ranges at startup, expected 22
I180917 20:21:20.699210 73089 storage/replica_command.go:298  [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180917 20:21:20.753047 72670 server/testserver.go:446  had 19 ranges at startup, expected 22
I180917 20:21:20.799566 73026 storage/replica_command.go:298  [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180917 20:21:20.880512 73213 storage/replica_command.go:298  [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
W180917 20:21:21.069657 72670 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180917 20:21:21.160860 72670 server/server.go:847  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180917 20:21:21.167539 72670 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:21.167672 72670 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:21.195331 72670 server/config.go:493  [n?] 1 storage engine initialized
I180917 20:21:21.195515 72670 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180917 20:21:21.195582 72670 server/config.go:496  [n?] store 0: in-memory, size 0 B
W180917 20:21:21.195965 72670 gossip/gossip.go:1516  [n?] no incoming or outgoing connections
I180917 20:21:21.196540 72670 server/server.go:1413  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I180917 20:21:21.273517 73229 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:37383
I180917 20:21:21.276107 73351 gossip/server.go:226  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:46731}
I180917 20:21:21.288473 72670 server/node.go:700  [n?] connecting to gossip network to verify cluster ID...
I180917 20:21:21.288832 72670 server/node.go:725  [n?] node connected via gossip and verified as part of cluster "7453afb9-0b32-433a-bb9d-6282b83b63ca"
I180917 20:21:21.289319 73318 gossip/gossip.go:940  [n?] gossip connectivity
  n1 [sentinel];
I180917 20:21:21.312023 72670 server/node.go:429  [n?] new node allocated ID 2
I180917 20:21:21.312764 72670 gossip/gossip.go:408  [n2] NodeDescriptor set to node_id:2 address:<network_field:"tcp" address_field:"127.0.0.1:46731" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-881-g7be4709" started_at:1537215681312318061 
I180917 20:21:21.313809 72670 storage/stores.go:242  [n2] read 0 node addresses from persistent storage
I180917 20:21:21.314239 72670 storage/stores.go:261  [n2] wrote 1 node addresses to persistent storage
I180917 20:21:21.316946 73318 gossip/gossip.go:940  [n2] gossip connectivity
  n1 [sentinel];
  n2 -> n1;
I180917 20:21:21.321620 72673 storage/stores.go:261  [n1] wrote 1 node addresses to persistent storage
I180917 20:21:21.322213 72774 gossip/gossip.go:940  [n1] gossip connectivity
  n1 [sentinel];
  n2 -> n1;
I180917 20:21:21.357801 72670 server/node.go:675  [n2] bootstrapped store [n2,s2]
I180917 20:21:21.360126 72670 server/node.go:549  [n2] node=2: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180917 20:21:21.361674 72670 server/status/recorder.go:611  [n2] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180917 20:21:21.361827 72670 server/server.go:1802  [n2] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180917 20:21:21.366348 72670 server/server.go:1548  [n2] starting https server at 127.0.0.1:34555 (use: 127.0.0.1:34555)
I180917 20:21:21.366600 72670 server/server.go:1550  [n2] starting grpc/postgres server at 127.0.0.1:46731
I180917 20:21:21.366685 72670 server/server.go:1551  [n2] advertising CockroachDB node at 127.0.0.1:46731
I180917 20:21:21.385692 72670 server/server.go:1604  [n2] done ensuring all necessary migrations have run
I180917 20:21:21.385849 72670 server/server.go:1607  [n2] serving sql connections
I180917 20:21:21.570865 73470 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n1 established
W180917 20:21:21.578628 72670 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180917 20:21:21.671157 73256 sql/event_log.go:126  [n2] Event: "node_join", target: 2, info: {Descriptor:{NodeID:2 Address:{NetworkField:tcp AddressField:127.0.0.1:46731} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-881-g7be4709 StartedAt:1537215681312318061 LocalityAddress:[]} ClusterID:7453afb9-0b32-433a-bb9d-6282b83b63ca StartedAt:1537215681312318061 LastUp:1537215681312318061}
I180917 20:21:21.682284 73254 server/server_update.go:67  [n2] no need to upgrade, cluster already at the newest version
I180917 20:21:21.682342 72774 gossip/gossip.go:1530  [n1] node has connected to cluster via gossip
I180917 20:21:21.683463 72774 storage/stores.go:261  [n1] wrote 1 node addresses to persistent storage
I180917 20:21:21.737594 73449 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n2 established
I180917 20:21:21.751108 72670 server/server.go:847  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180917 20:21:21.751903 72670 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:21.752032 72670 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:21.799146 72670 server/config.go:493  [n?] 1 storage engine initialized
I180917 20:21:21.799325 72670 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180917 20:21:21.799366 72670 server/config.go:496  [n?] store 0: in-memory, size 0 B
W180917 20:21:21.799689 72670 gossip/gossip.go:1516  [n?] no incoming or outgoing connections
I180917 20:21:21.800389 72670 server/server.go:1413  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I180917 20:21:21.868448 73571 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:37383
I180917 20:21:21.871085 73579 gossip/server.go:226  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:45667}
I180917 20:21:21.878059 72670 server/node.go:700  [n?] connecting to gossip network to verify cluster ID...
I180917 20:21:21.878477 72670 server/node.go:725  [n?] node connected via gossip and verified as part of cluster "7453afb9-0b32-433a-bb9d-6282b83b63ca"
I180917 20:21:21.884766 73457 gossip/gossip.go:940  [n?] gossip connectivity
  n1 [sentinel];
  n2 -> n1;
I180917 20:21:21.900855 72670 server/node.go:429  [n?] new node allocated ID 3
I180917 20:21:21.901455 72670 gossip/gossip.go:408  [n3] NodeDescriptor set to node_id:3 address:<network_field:"tcp" address_field:"127.0.0.1:45667" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-881-g7be4709" started_at:1537215681901061355 
I180917 20:21:21.902463 72670 storage/stores.go:242  [n3] read 0 node addresses from persistent storage
I180917 20:21:21.902834 72670 storage/stores.go:261  [n3] wrote 2 node addresses to persistent storage
I180917 20:21:21.905140 73457 gossip/gossip.go:940  [n3] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1;
I180917 20:21:21.910604 72673 storage/stores.go:261  [n1] wrote 2 node addresses to persistent storage
I180917 20:21:21.913519 72774 gossip/gossip.go:940  [n1] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1;
I180917 20:21:21.916322 73166 storage/stores.go:261  [n2] wrote 2 node addresses to persistent storage
I180917 20:21:21.917079 73318 gossip/gossip.go:940  [n2] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1;
I180917 20:21:21.948327 72670 server/node.go:675  [n3] bootstrapped store [n3,s3]
I180917 20:21:21.977188 72670 server/node.go:549  [n3] node=3: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180917 20:21:21.978841 72670 server/status/recorder.go:611  [n3] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180917 20:21:21.989541 72670 server/server.go:1802  [n3] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180917 20:21:21.992305 72670 server/server.go:1548  [n3] starting https server at 127.0.0.1:45697 (use: 127.0.0.1:45697)
I180917 20:21:21.992578 72670 server/server.go:1550  [n3] starting grpc/postgres server at 127.0.0.1:45667
I180917 20:21:21.992701 72670 server/server.go:1551  [n3] advertising CockroachDB node at 127.0.0.1:45667
I180917 20:21:22.030989 72670 server/server.go:1604  [n3] done ensuring all necessary migrations have run
I180917 20:21:22.031194 72670 server/server.go:1607  [n3] serving sql connections
I180917 20:21:22.143606 73481 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n1 established
I180917 20:21:22.295624 73764 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n3 established
I180917 20:21:22.297646 73480 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n2 established
I180917 20:21:22.300448 72926 rpc/nodedialer/nodedialer.go:92  [n1,replicate,s1,r4/1:/System/{NodeLive…-tsd}] connection to n3 established
I180917 20:21:22.339965 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r4/1:/System/{NodeLive…-tsd}] sending preemptive snapshot 75391233 at applied index 39
I180917 20:21:22.347047 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r4/1:/System/{NodeLive…-tsd}] streamed snapshot to (n3,s3):?: kv pairs: 37, log entries: 29, rate-limit: 8.0 MiB/sec, 44ms
I180917 20:21:22.359272 73570 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n3 established
W180917 20:21:22.361328 72670 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180917 20:21:22.391999 73761 storage/replica_raftstorage.go:803  [n3,s3,r4/?:{-}] applying preemptive snapshot at index 39 (id=75391233, encoded size=63189, 1 rocksdb batches, 29 log entries)
I180917 20:21:22.442683 73693 server/server_update.go:67  [n3] no need to upgrade, cluster already at the newest version
I180917 20:21:22.462840 73761 storage/replica_raftstorage.go:809  [n3,s3,r4/?:/System/{NodeLive…-tsd}] applied preemptive snapshot in 70ms [clear=1ms batch=5ms entries=36ms commit=28ms]
I180917 20:21:22.470603 72926 storage/replica_command.go:812  [n1,replicate,s1,r4/1:/System/{NodeLive…-tsd}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r4:/System/{NodeLivenessMax-tsd} [(n1,s1):1, next=2, gen=1]
I180917 20:21:22.529903 72670 server/server.go:847  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180917 20:21:22.530515 72670 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:22.530616 72670 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:22.575628 72926 storage/replica.go:3756  [n1,s1,r4/1:/System/{NodeLive…-tsd}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I180917 20:21:22.597271 72670 server/config.go:493  [n?] 1 storage engine initialized
I180917 20:21:22.606397 72670 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180917 20:21:22.606549 72670 server/config.go:496  [n?] store 0: in-memory, size 0 B
W180917 20:21:22.606874 72670 gossip/gossip.go:1516  [n?] no incoming or outgoing connections
I180917 20:21:22.606210 73695 sql/event_log.go:126  [n3] Event: "node_join", target: 3, info: {Descriptor:{NodeID:3 Address:{NetworkField:tcp AddressField:127.0.0.1:45667} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-881-g7be4709 StartedAt:1537215681901061355 LocalityAddress:[]} ClusterID:7453afb9-0b32-433a-bb9d-6282b83b63ca StartedAt:1537215681901061355 LastUp:1537215681901061355}
I180917 20:21:22.623225 72670 server/server.go:1413  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I180917 20:21:22.659263 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r9/1:/Table/1{2-3}] sending preemptive snapshot 6f5c3783 at applied index 30
I180917 20:21:22.661290 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r9/1:/Table/1{2-3}] streamed snapshot to (n2,s2):?: kv pairs: 52, log entries: 20, rate-limit: 8.0 MiB/sec, 17ms
I180917 20:21:22.667794 73892 storage/replica_raftstorage.go:803  [n2,s2,r9/?:{-}] applying preemptive snapshot at index 30 (id=6f5c3783, encoded size=17433, 1 rocksdb batches, 20 log entries)
I180917 20:21:22.676884 73892 storage/replica_raftstorage.go:809  [n2,s2,r9/?:/Table/1{2-3}] applied preemptive snapshot in 9ms [clear=0ms batch=0ms entries=7ms commit=0ms]
I180917 20:21:22.680658 72926 storage/replica_command.go:812  [n1,replicate,s1,r9/1:/Table/1{2-3}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r9:/Table/1{2-3} [(n1,s1):1, next=2, gen=1]
I180917 20:21:22.723628 73868 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:37383
I180917 20:21:22.736803 73939 gossip/server.go:226  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:42065}
I180917 20:21:22.745122 73866 gossip/gossip.go:940  [n?] gossip connectivity
  n1 [sentinel];
I180917 20:21:22.745368 72670 server/node.go:700  [n?] connecting to gossip network to verify cluster ID...
I180917 20:21:22.745681 72670 server/node.go:725  [n?] node connected via gossip and verified as part of cluster "7453afb9-0b32-433a-bb9d-6282b83b63ca"
I180917 20:21:22.749132 73866 gossip/gossip.go:940  [n?] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1;
I180917 20:21:22.766317 72926 storage/replica.go:3756  [n1,s1,r9/1:/Table/1{2-3}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I180917 20:21:22.780511 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r6/1:/{System/tse-Table/System…}] sending preemptive snapshot d3c9bf1c at applied index 20
I180917 20:21:22.784679 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r6/1:/{System/tse-Table/System…}] streamed snapshot to (n3,s3):?: kv pairs: 7, log entries: 10, rate-limit: 8.0 MiB/sec, 9ms
I180917 20:21:22.785452 72670 server/node.go:429  [n?] new node allocated ID 4
I180917 20:21:22.786169 72670 gossip/gossip.go:408  [n4] NodeDescriptor set to node_id:4 address:<network_field:"tcp" address_field:"127.0.0.1:42065" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-881-g7be4709" started_at:1537215682785749829 
I180917 20:21:22.786791 73940 storage/replica_raftstorage.go:803  [n3,s3,r6/?:{-}] applying preemptive snapshot at index 20 (id=d3c9bf1c, encoded size=4966, 1 rocksdb batches, 10 log entries)
I180917 20:21:22.789731 72670 storage/stores.go:242  [n4] read 0 node addresses from persistent storage
I180917 20:21:22.790329 73940 storage/replica_raftstorage.go:809  [n3,s3,r6/?:/{System/tse-Table/System…}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=2ms commit=0ms]
I180917 20:21:22.790574 72670 storage/stores.go:261  [n4] wrote 3 node addresses to persistent storage
I180917 20:21:22.790379 73866 gossip/gossip.go:940  [n4] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:22.796679 72926 storage/replica_command.go:812  [n1,replicate,s1,r6/1:/{System/tse-Table/System…}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r6:/{System/tse-Table/SystemConfigSpan/Start} [(n1,s1):1, next=2, gen=1]
I180917 20:21:22.801847 72673 storage/stores.go:261  [n1] wrote 3 node addresses to persistent storage
I180917 20:21:22.805124 73166 storage/stores.go:261  [n2] wrote 3 node addresses to persistent storage
I180917 20:21:22.805668 73318 gossip/gossip.go:940  [n2] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:22.805846 73279 storage/stores.go:261  [n3] wrote 3 node addresses to persistent storage
I180917 20:21:22.807370 73457 gossip/gossip.go:940  [n3] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:22.915790 72670 server/node.go:675  [n4] bootstrapped store [n4,s4]
I180917 20:21:22.918239 72670 server/node.go:549  [n4] node=4: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180917 20:21:22.919805 72670 server/status/recorder.go:611  [n4] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180917 20:21:22.919977 72670 server/server.go:1802  [n4] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180917 20:21:22.920473 72926 storage/replica.go:3756  [n1,s1,r6/1:/{System/tse-Table/System…}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I180917 20:21:22.947364 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r17/1:/Table/2{0-1}] sending preemptive snapshot 1599c94b at applied index 17
I180917 20:21:22.949236 72670 server/server.go:1548  [n4] starting https server at 127.0.0.1:36937 (use: 127.0.0.1:36937)
I180917 20:21:22.949404 72670 server/server.go:1550  [n4] starting grpc/postgres server at 127.0.0.1:42065
I180917 20:21:22.949474 72670 server/server.go:1551  [n4] advertising CockroachDB node at 127.0.0.1:42065
I180917 20:21:22.960373 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r17/1:/Table/2{0-1}] streamed snapshot to (n2,s2):?: kv pairs: 7, log entries: 7, rate-limit: 8.0 MiB/sec, 16ms
I180917 20:21:22.964960 72670 server/server.go:1604  [n4] done ensuring all necessary migrations have run
I180917 20:21:22.965170 72670 server/server.go:1607  [n4] serving sql connections
I180917 20:21:23.004053 74057 storage/replica_raftstorage.go:803  [n2,s2,r17/?:{-}] applying preemptive snapshot at index 17 (id=1599c94b, encoded size=2332, 1 rocksdb batches, 7 log entries)
I180917 20:21:23.006848 74057 storage/replica_raftstorage.go:809  [n2,s2,r17/?:/Table/2{0-1}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I180917 20:21:23.023583 72926 storage/replica_command.go:812  [n1,replicate,s1,r17/1:/Table/2{0-1}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r17:/Table/2{0-1} [(n1,s1):1, next=2, gen=1]
I180917 20:21:23.082600 73949 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n1 established
I180917 20:21:23.098839 73950 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n3 established
I180917 20:21:23.127860 73318 gossip/gossip.go:1530  [n2] node has connected to cluster via gossip
I180917 20:21:23.128937 73318 storage/stores.go:261  [n2] wrote 3 node addresses to persistent storage
W180917 20:21:23.192188 73946 jobs/registry.go:309  unable to get node liveness: node not in the liveness table
I180917 20:21:23.258866 72926 storage/replica.go:3756  [n1,s1,r17/1:/Table/2{0-1}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I180917 20:21:23.364390 73951 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n2 established
I180917 20:21:23.406919 73967 storage/replica_consistency.go:117  [n1,consistencyChecker,s1,r5/1:/System/ts{d-e}] triggering stats recomputation to resolve delta of {ContainsEstimates:true LastUpdateNanos:1537215682355136207 IntentAge:0 GCBytesAge:0 LiveBytes:-44800 LiveCount:-936 KeyBytes:-43594 KeyCount:-936 ValBytes:-1206 ValCount:-936 IntentBytes:0 IntentCount:0 SysBytes:0 SysCount:0}
I180917 20:21:23.468303 72926 rpc/nodedialer/nodedialer.go:92  [n1,replicate,s1,r15/1:/Table/1{8-9}] connection to n4 established
I180917 20:21:23.485278 73745 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n4 established
I180917 20:21:23.537325 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r15/1:/Table/1{8-9}] sending preemptive snapshot f1ca5ed1 at applied index 16
W180917 20:21:23.557242 72670 server/status/runtime.go:310  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180917 20:21:23.564458 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r15/1:/Table/1{8-9}] streamed snapshot to (n4,s4):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 77ms
I180917 20:21:23.589452 74165 storage/replica_raftstorage.go:803  [n4,s4,r15/?:{-}] applying preemptive snapshot at index 16 (id=f1ca5ed1, encoded size=2138, 1 rocksdb batches, 6 log entries)
I180917 20:21:23.593239 74165 storage/replica_raftstorage.go:809  [n4,s4,r15/?:/Table/1{8-9}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=1ms]
I180917 20:21:23.614942 72926 storage/replica_command.go:812  [n1,replicate,s1,r15/1:/Table/1{8-9}] change replicas (ADD_REPLICA (n4,s4):2): read existing descriptor r15:/Table/1{8-9} [(n1,s1):1, next=2, gen=1]
I180917 20:21:23.623517 74101 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n4 established
I180917 20:21:23.629872 74065 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n4 established
I180917 20:21:23.706879 72670 server/server.go:847  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180917 20:21:23.707757 72670 base/addr_validation.go:279  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:23.707884 72670 base/addr_validation.go:319  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180917 20:21:23.749645 72670 server/config.go:493  [n?] 1 storage engine initialized
I180917 20:21:23.749881 72670 server/config.go:496  [n?] RocksDB cache size: 128 MiB
I180917 20:21:23.749938 72670 server/config.go:496  [n?] store 0: in-memory, size 0 B
W180917 20:21:23.752458 72670 gossip/gossip.go:1516  [n?] no incoming or outgoing connections
I180917 20:21:23.763663 72670 server/server.go:1413  [n?] no stores bootstrapped and --join flag specified, awaiting init command.
I180917 20:21:23.779149 72926 storage/replica.go:3756  [n1,s1,r15/1:/Table/1{8-9}] proposing ADD_REPLICA((n4,s4):2): updated=[(n1,s1):1 (n4,s4):2] next=3
I180917 20:21:23.781849 73887 server/server_update.go:67  [n4] no need to upgrade, cluster already at the newest version
I180917 20:21:23.807535 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r18/1:/Table/2{1-2}] sending preemptive snapshot c685f76c at applied index 16
I180917 20:21:23.815353 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r18/1:/Table/2{1-2}] streamed snapshot to (n4,s4):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 22ms
I180917 20:21:23.861077 74282 storage/replica_raftstorage.go:803  [n4,s4,r18/?:{-}] applying preemptive snapshot at index 16 (id=c685f76c, encoded size=2134, 1 rocksdb batches, 6 log entries)
I180917 20:21:23.865045 74282 storage/replica_raftstorage.go:809  [n4,s4,r18/?:/Table/2{1-2}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=1ms]
I180917 20:21:23.870833 72926 storage/replica_command.go:812  [n1,replicate,s1,r18/1:/Table/2{1-2}] change replicas (ADD_REPLICA (n4,s4):2): read existing descriptor r18:/Table/2{1-2} [(n1,s1):1, next=2, gen=1]
I180917 20:21:23.876264 72774 gossip/gossip.go:940  [n1] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:23.909597 73889 sql/event_log.go:126  [n4] Event: "node_join", target: 4, info: {Descriptor:{NodeID:4 Address:{NetworkField:tcp AddressField:127.0.0.1:42065} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-881-g7be4709 StartedAt:1537215682785749829 LocalityAddress:[]} ClusterID:7453afb9-0b32-433a-bb9d-6282b83b63ca StartedAt:1537215682785749829 LastUp:1537215682785749829}
I180917 20:21:23.974090 73457 gossip/gossip.go:1530  [n3] node has connected to cluster via gossip
I180917 20:21:23.975216 73457 storage/stores.go:261  [n3] wrote 3 node addresses to persistent storage
I180917 20:21:23.981916 72926 storage/replica.go:3756  [n1,s1,r18/1:/Table/2{1-2}] proposing ADD_REPLICA((n4,s4):2): updated=[(n1,s1):1 (n4,s4):2] next=3
I180917 20:21:23.983888 74186 gossip/client.go:129  [n?] started gossip client to 127.0.0.1:37383
I180917 20:21:23.988007 74173 gossip/server.go:226  [n1] received initial cluster-verification connection from {tcp 127.0.0.1:45375}
I180917 20:21:23.996631 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r11/1:/Table/1{4-5}] sending preemptive snapshot 2fd0d9e3 at applied index 17
I180917 20:21:23.997997 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r11/1:/Table/1{4-5}] streamed snapshot to (n4,s4):?: kv pairs: 7, log entries: 7, rate-limit: 8.0 MiB/sec, 5ms
I180917 20:21:24.007017 74223 gossip/gossip.go:940  [n?] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:24.015382 74201 storage/replica_raftstorage.go:803  [n4,s4,r11/?:{-}] applying preemptive snapshot at index 17 (id=2fd0d9e3, encoded size=2334, 1 rocksdb batches, 7 log entries)
I180917 20:21:24.016703 72670 server/node.go:700  [n?] connecting to gossip network to verify cluster ID...
I180917 20:21:24.017109 72670 server/node.go:725  [n?] node connected via gossip and verified as part of cluster "7453afb9-0b32-433a-bb9d-6282b83b63ca"
I180917 20:21:24.019167 74201 storage/replica_raftstorage.go:809  [n4,s4,r11/?:/Table/1{4-5}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=2ms commit=0ms]
I180917 20:21:24.027386 72926 storage/replica_command.go:812  [n1,replicate,s1,r11/1:/Table/1{4-5}] change replicas (ADD_REPLICA (n4,s4):2): read existing descriptor r11:/Table/1{4-5} [(n1,s1):1, next=2, gen=1]
I180917 20:21:24.065227 72670 server/node.go:429  [n?] new node allocated ID 5
I180917 20:21:24.065869 72670 gossip/gossip.go:408  [n5] NodeDescriptor set to node_id:5 address:<network_field:"tcp" address_field:"127.0.0.1:45375" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:13 > build_tag:"v2.2.0-alpha.00000000-881-g7be4709" started_at:1537215684065458688 
I180917 20:21:24.066987 72670 storage/stores.go:242  [n5] read 0 node addresses from persistent storage
I180917 20:21:24.067387 72670 storage/stores.go:261  [n5] wrote 4 node addresses to persistent storage
I180917 20:21:24.070270 74223 gossip/gossip.go:940  [n5] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n1;
I180917 20:21:24.075470 74173 gossip/server.go:276  [n1] refusing gossip from node 5 (max 3 conns); forwarding to 4 ({tcp 127.0.0.1:42065})
I180917 20:21:24.079786 72673 storage/stores.go:261  [n1] wrote 4 node addresses to persistent storage
I180917 20:21:24.081257 74186 gossip/client.go:134  [n5] closing client to node 1 (127.0.0.1:37383): received forward from node 1 to 4 (127.0.0.1:42065)
I180917 20:21:24.082118 74223 gossip/gossip.go:1530  [n5] node has connected to cluster via gossip
I180917 20:21:24.083058 74223 storage/stores.go:261  [n5] wrote 4 node addresses to persistent storage
I180917 20:21:24.083957 74223 gossip/gossip.go:940  [n5] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:24.091716 73166 storage/stores.go:261  [n2] wrote 4 node addresses to persistent storage
I180917 20:21:24.092785 73318 gossip/gossip.go:940  [n2] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n1;
I180917 20:21:24.093938 73279 storage/stores.go:261  [n3] wrote 4 node addresses to persistent storage
I180917 20:21:24.096519 73713 storage/stores.go:261  [n4] wrote 4 node addresses to persistent storage
I180917 20:21:24.112254 73866 gossip/gossip.go:940  [n4] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n1;
I180917 20:21:24.120552 73457 gossip/gossip.go:940  [n3] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n1;
I180917 20:21:24.153103 72926 storage/replica.go:3756  [n1,s1,r11/1:/Table/1{4-5}] proposing ADD_REPLICA((n4,s4):2): updated=[(n1,s1):1 (n4,s4):2] next=3
I180917 20:21:24.172926 74206 gossip/client.go:129  [n5] started gossip client to 127.0.0.1:42065
I180917 20:21:24.183282 72670 server/node.go:675  [n5] bootstrapped store [n5,s5]
I180917 20:21:24.185950 72670 server/node.go:549  [n5] node=5: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180917 20:21:24.187570 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r12/1:/Table/1{5-6}] sending preemptive snapshot 5de7e901 at applied index 16
I180917 20:21:24.208621 73866 gossip/gossip.go:940  [n4] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1;
I180917 20:21:24.213112 74223 gossip/gossip.go:940  [n5] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n4;
I180917 20:21:24.216068 73866 gossip/gossip.go:940  [n4] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n4;
I180917 20:21:24.217627 72670 server/status/recorder.go:611  [n5] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180917 20:21:24.217839 72670 server/server.go:1802  [n5] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180917 20:21:24.219812 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r12/1:/Table/1{5-6}] streamed snapshot to (n3,s3):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 47ms
I180917 20:21:24.283775 72774 gossip/gossip.go:940  [n1] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n4;
I180917 20:21:24.286400 74331 storage/replica_raftstorage.go:803  [n3,s3,r12/?:{-}] applying preemptive snapshot at index 16 (id=5de7e901, encoded size=1967, 1 rocksdb batches, 6 log entries)
I180917 20:21:24.287565 72670 server/server.go:1548  [n5] starting https server at 127.0.0.1:46575 (use: 127.0.0.1:46575)
I180917 20:21:24.287773 72670 server/server.go:1550  [n5] starting grpc/postgres server at 127.0.0.1:45375
I180917 20:21:24.289764 72670 server/server.go:1551  [n5] advertising CockroachDB node at 127.0.0.1:45375
I180917 20:21:24.297416 73318 gossip/gossip.go:940  [n2] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n4;
I180917 20:21:24.302968 73457 gossip/gossip.go:940  [n3] gossip connectivity
  n1 [sentinel];
  n2 -> n1; n3 -> n1; n4 -> n1; n5 -> n4;
I180917 20:21:24.322544 74331 storage/replica_raftstorage.go:809  [n3,s3,r12/?:/Table/1{5-6}] applied preemptive snapshot in 36ms [clear=1ms batch=0ms entries=33ms commit=0ms]
I180917 20:21:24.338290 72926 storage/replica_command.go:812  [n1,replicate,s1,r12/1:/Table/1{5-6}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r12:/Table/1{5-6} [(n1,s1):1, next=2, gen=1]
I180917 20:21:24.353079 72670 server/server.go:1604  [n5] done ensuring all necessary migrations have run
I180917 20:21:24.353289 72670 server/server.go:1607  [n5] serving sql connections
I180917 20:21:24.395965 73866 gossip/gossip.go:1530  [n4] node has connected to cluster via gossip
I180917 20:21:24.399336 73866 storage/stores.go:261  [n4] wrote 4 node addresses to persistent storage
I180917 20:21:24.440119 74317 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n1 established
I180917 20:21:24.443252 74316 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n4 established
I180917 20:21:24.446942 74427 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n3 established
I180917 20:21:24.558143 72926 storage/replica.go:3756  [n1,s1,r12/1:/Table/1{5-6}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I180917 20:21:24.701559 72926 rpc/nodedialer/nodedialer.go:92  [n1,replicate,s1,r19/1:/Table/2{2-3}] connection to n5 established
I180917 20:21:24.706401 74269 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n5 established
I180917 20:21:24.711537 74322 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n5 established
I180917 20:21:24.732194 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r19/1:/Table/2{2-3}] sending preemptive snapshot 9a18531e at applied index 16
I180917 20:21:24.735813 74348 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n2 established
I180917 20:21:24.738574 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r19/1:/Table/2{2-3}] streamed snapshot to (n5,s5):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 36ms
I180917 20:21:24.779241 74511 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n5 established
I180917 20:21:24.785588 74447 storage/replica_raftstorage.go:803  [n5,s5,r19/?:{-}] applying preemptive snapshot at index 16 (id=9a18531e, encoded size=2138, 1 rocksdb batches, 6 log entries)
I180917 20:21:24.900656 74447 storage/replica_raftstorage.go:809  [n5,s5,r19/?:/Table/2{2-3}] applied preemptive snapshot in 113ms [clear=40ms batch=0ms entries=67ms commit=1ms]
I180917 20:21:24.937175 74548 rpc/nodedialer/nodedialer.go:92  [ct-client] connection to n5 established
I180917 20:21:24.955891 72926 storage/replica_command.go:812  [n1,replicate,s1,r19/1:/Table/2{2-3}] change replicas (ADD_REPLICA (n5,s5):2): read existing descriptor r19:/Table/2{2-3} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.011314 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.044471 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.133469 72926 storage/replica.go:3756  [n1,s1,r19/1:/Table/2{2-3}] proposing ADD_REPLICA((n5,s5):2): updated=[(n1,s1):1 (n5,s5):2] next=3
I180917 20:21:25.137245 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.171523 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r5/1:/System/ts{d-e}] sending preemptive snapshot 7f51d238 at applied index 30
I180917 20:21:25.204866 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.230318 74500 server/server_update.go:67  [n5] no need to upgrade, cluster already at the newest version
I180917 20:21:25.241522 74502 sql/event_log.go:126  [n5] Event: "node_join", target: 5, info: {Descriptor:{NodeID:5 Address:{NetworkField:tcp AddressField:127.0.0.1:45375} Attrs: Locality: ServerVersion:2.0-13 BuildTag:v2.2.0-alpha.00000000-881-g7be4709 StartedAt:1537215684065458688 LocalityAddress:[]} ClusterID:7453afb9-0b32-433a-bb9d-6282b83b63ca StartedAt:1537215684065458688 LastUp:1537215684065458688}
I180917 20:21:25.288552 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.326108 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r5/1:/System/ts{d-e}] streamed snapshot to (n3,s3):?: kv pairs: 2349, log entries: 2, rate-limit: 8.0 MiB/sec, 183ms
I180917 20:21:25.343344 74575 storage/replica_raftstorage.go:803  [n3,s3,r5/?:{-}] applying preemptive snapshot at index 30 (id=7f51d238, encoded size=291302, 1 rocksdb batches, 2 log entries)
I180917 20:21:25.396156 74575 storage/replica_raftstorage.go:809  [n3,s3,r5/?:/System/ts{d-e}] applied preemptive snapshot in 52ms [clear=0ms batch=11ms entries=36ms commit=2ms]
I180917 20:21:25.408724 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.412586 72926 storage/replica_command.go:812  [n1,replicate,s1,r5/1:/System/ts{d-e}] change replicas (ADD_REPLICA (n3,s3):2): read existing descriptor r5:/System/ts{d-e} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.450693 72926 storage/replica.go:3756  [n1,s1,r5/1:/System/ts{d-e}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I180917 20:21:25.499118 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r8/1:/Table/1{1-2}] sending preemptive snapshot 3ff72ac2 at applied index 20
I180917 20:21:25.500402 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r8/1:/Table/1{1-2}] streamed snapshot to (n5,s5):?: kv pairs: 8, log entries: 10, rate-limit: 8.0 MiB/sec, 10ms
I180917 20:21:25.505147 74654 storage/replica_raftstorage.go:803  [n5,s5,r8/?:{-}] applying preemptive snapshot at index 20 (id=3ff72ac2, encoded size=4191, 1 rocksdb batches, 10 log entries)
I180917 20:21:25.511467 74654 storage/replica_raftstorage.go:809  [n5,s5,r8/?:/Table/1{1-2}] applied preemptive snapshot in 6ms [clear=0ms batch=0ms entries=3ms commit=2ms]
I180917 20:21:25.521194 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.523461 72926 storage/replica_command.go:812  [n1,replicate,s1,r8/1:/Table/1{1-2}] change replicas (ADD_REPLICA (n5,s5):2): read existing descriptor r8:/Table/1{1-2} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.575697 72926 storage/replica.go:3756  [n1,s1,r8/1:/Table/1{1-2}] proposing ADD_REPLICA((n5,s5):2): updated=[(n1,s1):1 (n5,s5):2] next=3
I180917 20:21:25.603762 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r14/1:/Table/1{7-8}] sending preemptive snapshot 2dcb589b at applied index 16
I180917 20:21:25.604975 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r14/1:/Table/1{7-8}] streamed snapshot to (n5,s5):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 5ms
I180917 20:21:25.611235 74668 storage/replica_raftstorage.go:803  [n5,s5,r14/?:{-}] applying preemptive snapshot at index 16 (id=2dcb589b, encoded size=2134, 1 rocksdb batches, 6 log entries)
I180917 20:21:25.614473 74668 storage/replica_raftstorage.go:809  [n5,s5,r14/?:/Table/1{7-8}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I180917 20:21:25.619301 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.623813 72926 storage/replica_command.go:812  [n1,replicate,s1,r14/1:/Table/1{7-8}] change replicas (ADD_REPLICA (n5,s5):2): read existing descriptor r14:/Table/1{7-8} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.690827 72926 storage/replica.go:3756  [n1,s1,r14/1:/Table/1{7-8}] proposing ADD_REPLICA((n5,s5):2): updated=[(n1,s1):1 (n5,s5):2] next=3
I180917 20:21:25.711283 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r20/1:/Table/{23-50}] sending preemptive snapshot 8f340362 at applied index 16
I180917 20:21:25.712576 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r20/1:/Table/{23-50}] streamed snapshot to (n5,s5):?: kv pairs: 11, log entries: 6, rate-limit: 8.0 MiB/sec, 5ms
I180917 20:21:25.722368 74494 storage/replica_raftstorage.go:803  [n5,s5,r20/?:{-}] applying preemptive snapshot at index 16 (id=8f340362, encoded size=2103, 1 rocksdb batches, 6 log entries)
I180917 20:21:25.738442 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.743653 74494 storage/replica_raftstorage.go:809  [n5,s5,r20/?:/Table/{23-50}] applied preemptive snapshot in 21ms [clear=0ms batch=0ms entries=18ms commit=1ms]
I180917 20:21:25.766151 72926 storage/replica_command.go:812  [n1,replicate,s1,r20/1:/Table/{23-50}] change replicas (ADD_REPLICA (n5,s5):2): read existing descriptor r20:/Table/{23-50} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.844959 72926 storage/replica.go:3756  [n1,s1,r20/1:/Table/{23-50}] proposing ADD_REPLICA((n5,s5):2): updated=[(n1,s1):1 (n5,s5):2] next=3
I180917 20:21:25.859266 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r13/1:/Table/1{6-7}] sending preemptive snapshot bb96d8a4 at applied index 16
I180917 20:21:25.861353 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r13/1:/Table/1{6-7}] streamed snapshot to (n2,s2):?: kv pairs: 7, log entries: 6, rate-limit: 8.0 MiB/sec, 9ms
I180917 20:21:25.864125 74710 storage/replica_raftstorage.go:803  [n2,s2,r13/?:{-}] applying preemptive snapshot at index 16 (id=bb96d8a4, encoded size=1967, 1 rocksdb batches, 6 log entries)
I180917 20:21:25.866703 74710 storage/replica_raftstorage.go:809  [n2,s2,r13/?:/Table/1{6-7}] applied preemptive snapshot in 2ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I180917 20:21:25.899188 72926 storage/replica_command.go:812  [n1,replicate,s1,r13/1:/Table/1{6-7}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r13:/Table/1{6-7} [(n1,s1):1, next=2, gen=1]
I180917 20:21:25.917110 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:25.983746 72926 storage/replica.go:3756  [n1,s1,r13/1:/Table/1{6-7}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I180917 20:21:26.008072 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r7/1:/Table/{SystemCon…-11}] sending preemptive snapshot 5dd4242d at applied index 30
I180917 20:21:26.010967 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r7/1:/Table/{SystemCon…-11}] streamed snapshot to (n2,s2):?: kv pairs: 59, log entries: 20, rate-limit: 8.0 MiB/sec, 6ms
I180917 20:21:26.015057 74496 storage/replica_raftstorage.go:803  [n2,s2,r7/?:{-}] applying preemptive snapshot at index 30 (id=5dd4242d, encoded size=15881, 1 rocksdb batches, 20 log entries)
I180917 20:21:26.020275 74496 storage/replica_raftstorage.go:809  [n2,s2,r7/?:/Table/{SystemCon…-11}] applied preemptive snapshot in 5ms [clear=0ms batch=0ms entries=3ms commit=0ms]
I180917 20:21:26.024427 72926 storage/replica_command.go:812  [n1,replicate,s1,r7/1:/Table/{SystemCon…-11}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r7:/Table/{SystemConfigSpan/Start-11} [(n1,s1):1, next=2, gen=1]
I180917 20:21:26.038513 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.146129 72926 storage/replica.go:3756  [n1,s1,r7/1:/Table/{SystemCon…-11}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I180917 20:21:26.182109 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.190223 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r22/1:/{Table/51-Max}] sending preemptive snapshot cee417d9 at applied index 12
I180917 20:21:26.192501 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r22/1:/{Table/51-Max}] streamed snapshot to (n4,s4):?: kv pairs: 6, log entries: 2, rate-limit: 8.0 MiB/sec, 14ms
I180917 20:21:26.194694 74658 storage/replica_raftstorage.go:803  [n4,s4,r22/?:{-}] applying preemptive snapshot at index 12 (id=cee417d9, encoded size=317, 1 rocksdb batches, 2 log entries)
I180917 20:21:26.199698 74658 storage/replica_raftstorage.go:809  [n4,s4,r22/?:/{Table/51-Max}] applied preemptive snapshot in 5ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I180917 20:21:26.208500 72926 storage/replica_command.go:812  [n1,replicate,s1,r22/1:/{Table/51-Max}] change replicas (ADD_REPLICA (n4,s4):2): read existing descriptor r22:/{Table/51-Max} [(n1,s1):1, next=2, gen=0]
I180917 20:21:26.270185 72926 storage/replica.go:3756  [n1,s1,r22/1:/{Table/51-Max}] proposing ADD_REPLICA((n4,s4):2): updated=[(n1,s1):1 (n4,s4):2] next=3
I180917 20:21:26.296286 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r2/1:/System/{-NodeLive…}] sending preemptive snapshot a8a75d98 at applied index 23
I180917 20:21:26.298648 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r2/1:/System/{-NodeLive…}] streamed snapshot to (n5,s5):?: kv pairs: 8, log entries: 13, rate-limit: 8.0 MiB/sec, 11ms
I180917 20:21:26.302949 74696 storage/replica_raftstorage.go:803  [n5,s5,r2/?:{-}] applying preemptive snapshot at index 23 (id=a8a75d98, encoded size=23379, 1 rocksdb batches, 13 log entries)
I180917 20:21:26.305121 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.316189 74696 storage/replica_raftstorage.go:809  [n5,s5,r2/?:/System/{-NodeLive…}] applied preemptive snapshot in 13ms [clear=0ms batch=0ms entries=9ms commit=2ms]
I180917 20:21:26.326061 72926 storage/replica_command.go:812  [n1,replicate,s1,r2/1:/System/{-NodeLive…}] change replicas (ADD_REPLICA (n5,s5):2): read existing descriptor r2:/System/{-NodeLiveness} [(n1,s1):1, next=2, gen=1]
I180917 20:21:26.400859 72926 storage/replica.go:3756  [n1,s1,r2/1:/System/{-NodeLive…}] proposing ADD_REPLICA((n5,s5):2): updated=[(n1,s1):1 (n5,s5):2] next=3
I180917 20:21:26.432461 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r3/1:/System/NodeLiveness{-Max}] sending preemptive snapshot c1bbc7e9 at applied index 29
I180917 20:21:26.433988 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r3/1:/System/NodeLiveness{-Max}] streamed snapshot to (n2,s2):?: kv pairs: 15, log entries: 19, rate-limit: 8.0 MiB/sec, 5ms
I180917 20:21:26.459511 74609 storage/replica_raftstorage.go:803  [n2,s2,r3/?:{-}] applying preemptive snapshot at index 29 (id=c1bbc7e9, encoded size=5688, 1 rocksdb batches, 19 log entries)
I180917 20:21:26.476329 74609 storage/replica_raftstorage.go:809  [n2,s2,r3/?:/System/NodeLiveness{-Max}] applied preemptive snapshot in 16ms [clear=0ms batch=0ms entries=3ms commit=12ms]
I180917 20:21:26.483564 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.485612 72926 storage/replica_command.go:812  [n1,replicate,s1,r3/1:/System/NodeLiveness{-Max}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r3:/System/NodeLiveness{-Max} [(n1,s1):1, next=2, gen=1]
I180917 20:21:26.528135 72919 storage/replica_proposal.go:211  [n1,s1,r7/1:/Table/{SystemCon…-11}] new range lease repl=(n1,s1):1 seq=3 start=1537215677.996699967,0 epo=1 pro=1537215686.515651206,0 following repl=(n1,s1):1 seq=2 start=1537215677.996699967,0 exp=1537215687.011717417,0 pro=1537215678.011789479,0
I180917 20:21:26.557981 72914 storage/replica_proposal.go:211  [n1,s1,r10/1:/Table/1{3-4}] new range lease repl=(n1,s1):1 seq=3 start=1537215677.996699967,0 epo=1 pro=1537215686.553713003,0 following repl=(n1,s1):1 seq=2 start=1537215677.996699967,0 exp=1537215687.011717417,0 pro=1537215678.011789479,0
I180917 20:21:26.601606 72926 storage/replica.go:3756  [n1,s1,r3/1:/System/NodeLiveness{-Max}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I180917 20:21:26.645743 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.650442 72904 storage/replica_proposal.go:211  [n1,s1,r16/1:/Table/{19-20}] new range lease repl=(n1,s1):1 seq=3 start=1537215677.996699967,0 epo=1 pro=1537215686.638129876,0 following repl=(n1,s1):1 seq=2 start=1537215677.996699967,0 exp=1537215687.011717417,0 pro=1537215678.011789479,0
I180917 20:21:26.667976 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r16/1:/Table/{19-20}] sending preemptive snapshot 588624f9 at applied index 17
I180917 20:21:26.672955 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r16/1:/Table/{19-20}] streamed snapshot to (n4,s4):?: kv pairs: 7, log entries: 7, rate-limit: 8.0 MiB/sec, 8ms
I180917 20:21:26.676059 74690 storage/replica_raftstorage.go:803  [n4,s4,r16/?:{-}] applying preemptive snapshot at index 17 (id=588624f9, encoded size=2305, 1 rocksdb batches, 7 log entries)
I180917 20:21:26.679239 74690 storage/replica_raftstorage.go:809  [n4,s4,r16/?:/Table/{19-20}] applied preemptive snapshot in 3ms [clear=0ms batch=0ms entries=1ms commit=0ms]
I180917 20:21:26.683508 72926 storage/replica_command.go:812  [n1,replicate,s1,r16/1:/Table/{19-20}] change replicas (ADD_REPLICA (n4,s4):2): read existing descriptor r16:/Table/{19-20} [(n1,s1):1, next=2, gen=1]
I180917 20:21:26.722114 72926 storage/replica.go:3756  [n1,s1,r16/1:/Table/{19-20}] proposing ADD_REPLICA((n4,s4):2): updated=[(n1,s1):1 (n4,s4):2] next=3
I180917 20:21:26.744503 72926 storage/store_snapshot.go:615  [n1,replicate,s1,r1/1:/{Min-System/}] sending preemptive snapshot 9709cd6a at applied index 109
I180917 20:21:26.756980 72926 storage/store_snapshot.go:657  [n1,replicate,s1,r1/1:/{Min-System/}] streamed snapshot to (n3,s3):?: kv pairs: 72, log entries: 61, rate-limit: 8.0 MiB/sec, 19ms
I180917 20:21:26.760714 74748 storage/replica_raftstorage.go:803  [n3,s3,r1/?:{-}] applying preemptive snapshot at index 109 (id=9709cd6a, encoded size=14495, 1 rocksdb batches, 61 log entries)
I180917 20:21:26.771266 72670 testutils/testcluster/testcluster.go:537  [n1,s1] has 22 underreplicated ranges
I180917 20:21:26.798932 74748 storage/replica_raftstorage.go:809  [n3,s3,r1/?:/{Min-System/}] applied preemptive snapshot in 38ms [clear=0ms batch=0ms entries=35ms commit=1ms]
I180917

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

jordanlewis commented 6 years ago 
unexpected fault address 0x2400
fatal error: fault
[signal SIGSEGV: segmentation violation code=0x1 addr=0x2400 pc=0x2c17bf9]

goroutine 89108 [running]:
runtime.throw(0x896b22, 0x2)
    /usr/local/go/src/runtime/panic.go:608 +0x72 fp=0x7f50145fe9a0 sp=0x7f50145fe970 pc=0x86a862
runtime.recordForPanic(0x33a4866, 0x3, 0x3)
    /usr/local/go/src/runtime/print.go:53 +0x12e fp=0x7f50145fe9d8 sp=0x7f50145fe9a0 pc=0x86b22e
runtime.gwrite(0x33a4866, 0x3, 0x3)
    /usr/local/go/src/runtime/print.go:93 +0x113 fp=0x7f50145fea10 sp=0x7f50145fe9d8 pc=0x86b453
runtime.printstring(0x7f50145fea98, 0x891ad2)
    /usr/local/go/src/runtime/print.go:237 +0x78 fp=0x7f50145fea60 sp=0x7f50145fea10 pc=0x86bbe8
runtime.goroutineheader(0x86a862)
    /usr/local/go/src/runtime/traceback.go:908 +0x16f fp=0x7f50145feaa8 sp=0x7f50145fea60 pc=0x892c8f
runtime.dopanic_m(0xc006fe7500, 0x86a862, 0x7f50145fe970, 0x33a6bf7)
    /usr/local/go/src/runtime/panic.go:798 +0x30d fp=0x7f50145feb10 sp=0x7f50145feaa8 pc=0x86afcd
runtime.fatalthrow.func1()
    /usr/local/go/src/runtime/panic.go:663 +0x5f fp=0x7f50145feb58 sp=0x7f50145feb10 pc=0x8988ef
runtime.systemstack(0x7f50145ff3c8)
    /usr/local/go/src/runtime/asm_amd64.s:351 +0x66 fp=0x7f50145feb60 sp=0x7f50145feb58 pc=0x899ef6
runtime.mstart()
    /usr/local/go/src/runtime/proc.go:1229 fp=0x7f50145feb68 sp=0x7f50145feb60 pc=0x86f150
created by github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).serveStreams.func1
    /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:678 +0xb9

Another one for #30334.