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.9k stars 3.78k forks source link

teamcity: failed tests on master: test/TestImportData, testrace/TestImportData #29150

Closed cockroach-teamcity closed 5 years ago

cockroach-teamcity commented 6 years ago

The following tests appear to have failed:

#864548:

--- FAIL: testrace/TestImportData/PGDUMP:_too_many_cols (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:58.317879 5115 storage/replica_command.go:298  [split,n1,s1,r110/1:/{Table/123-Max}] initiating a split of this range at key /Table/124 [r111]
I180827 20:19:58.338633 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 124, info: {DatabaseName:d37 Statement:CREATE DATABASE d37 User:root}
I180827 20:19:58.402031 205 storage/replica_proposal.go:211  [n1,s1,r110/1:/{Table/123-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:58.564842 5162 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:58.715430 5038 storage/replica_command.go:298  [split,n1,s1,r111/1:/{Table/124-Max}] initiating a split of this range at key /Table/125 [r112]
I180827 20:19:58.812894 234 storage/replica_proposal.go:211  [n1,s1,r111/1:/{Table/124-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:58.815666 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 124, info: {DatabaseName:d37 Statement:DROP DATABASE d37 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData (0.000s)
Test ended in panic.

------- Stdout: -------
W180827 20:19:24.779606 54 server/status/runtime.go:294  [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180827 20:19:24.842167 54 server/server.go:830  [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled
I180827 20:19:24.847286 54 base/addr_validation.go:260  [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180827 20:19:24.847464 54 base/addr_validation.go:300  [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node
I180827 20:19:24.881940 54 server/config.go:496  [n?] 1 storage engine initialized
I180827 20:19:24.882110 54 server/config.go:499  [n?] RocksDB cache size: 128 MiB
I180827 20:19:24.882162 54 server/config.go:499  [n?] store 0: in-memory, size 0 B
I180827 20:19:24.950312 178 util/protoutil/randnullability.go:94  inserting null for (storagebase.ReplicaState).GCThreshold: false
I180827 20:19:24.950428 178 util/protoutil/randnullability.go:94  inserting null for (storagebase.ReplicaState).TxnSpanGCThreshold: false
I180827 20:19:24.961992 54 server/node.go:373  [n?] **** cluster 11dfb876-012b-4855-8cf1-8c567d94bb72 has been created
I180827 20:19:24.962178 54 server/server.go:1401  [n?] **** add additional nodes by specifying --join=127.0.0.1:39605
I180827 20:19:24.963505 54 gossip/gossip.go:382  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:39605" > attrs:<> locality:<> ServerVersion:<major_val:2 minor_val:0 patch:0 unstable:12 > build_tag:"v2.1.0-alpha.20180702-2029-g9781d76" started_at:1535401164962835637 
I180827 20:19:24.983988 54 storage/store.go:1540  [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available
I180827 20:19:24.985151 54 server/node.go:476  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=6.9 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7103.00 p25=7103.00 p50=7103.00 p75=7103.00 p90=7103.00 pMax=7103.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00}
I180827 20:19:24.985512 54 storage/stores.go:242  [n1] read 0 node addresses from persistent storage
I180827 20:19:24.986103 54 server/node.go:697  [n1] connecting to gossip network to verify cluster ID...
I180827 20:19:24.988716 54 server/node.go:722  [n1] node connected via gossip and verified as part of cluster "11dfb876-012b-4855-8cf1-8c567d94bb72"
I180827 20:19:24.989360 54 server/node.go:546  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180827 20:19:24.990657 54 server/status/recorder.go:652  [n1] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:19:24.990845 54 server/server.go:1807  [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined
I180827 20:19:24.993410 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:19:25.009377 54 server/server.go:1538  [n1] starting https server at 127.0.0.1:34489 (use: 127.0.0.1:34489)
I180827 20:19:25.009567 54 server/server.go:1540  [n1] starting grpc/postgres server at 127.0.0.1:39605
I180827 20:19:25.009694 54 server/server.go:1541  [n1] advertising CockroachDB node at 127.0.0.1:39605
W180827 20:19:25.012215 54 jobs/registry.go:309  [n1] unable to get node liveness: node not in the liveness table
I180827 20:19:25.055751 327 storage/replica_command.go:298  [split,n1,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180827 20:19:25.183227 331 storage/replica_command.go:298  [split,n1,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
I180827 20:19:25.307543 285 sql/event_log.go:126  [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root}
I180827 20:19:25.451460 297 storage/replica_command.go:298  [split,n1,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
I180827 20:19:25.584469 220 storage/replica_command.go:298  [split,n1,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180827 20:19:25.665622 360 storage/replica_command.go:298  [split,n1,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
W180827 20:19:25.670839 221 storage/intent_resolver.go:668  [n1,s1] failed to push during intent resolution: failed to push "unnamed" id=7e999e54 key=/Table/SystemConfigSpan/Start rw=true pri=0.01472132 iso=SERIALIZABLE stat=PENDING epo=0 ts=1535401165.522063775,0 orig=1535401165.522063775,0 max=1535401165.522063775,0 wto=false rop=false seq=12
I180827 20:19:25.712970 300 sql/event_log.go:126  [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.0-12 User:root}
I180827 20:19:25.784418 402 storage/replica_command.go:298  [split,n1,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180827 20:19:25.855218 320 sql/event_log.go:126  [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root}
I180827 20:19:25.862146 345 storage/replica_command.go:298  [split,n1,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
I180827 20:19:25.931191 348 storage/replica_command.go:298  [split,n1,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180827 20:19:25.998376 377 storage/replica_command.go:298  [split,n1,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180827 20:19:26.036993 442 storage/replica_command.go:298  [split,n1,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180827 20:19:26.086873 393 storage/replica_command.go:298  [split,n1,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180827 20:19:26.116622 391 sql/event_log.go:126  [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:90ac5da0-0230-4f3b-aa0b-94eebb52c71a User:root}
I180827 20:19:26.183028 352 rpc/nodedialer/nodedialer.go:92  [consistencyChecker,n1,s1,r1/1:/{Min-System/}] connection to n1 established
I180827 20:19:26.211570 430 storage/replica_command.go:298  [split,n1,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180827 20:19:26.257188 475 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}
I180827 20:19:26.279872 478 storage/replica_command.go:298  [split,n1,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180827 20:19:26.324887 476 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}
I180827 20:19:26.356147 54 server/server.go:1594  [n1] done ensuring all necessary migrations have run
I180827 20:19:26.356435 54 server/server.go:1597  [n1] serving sql connections
I180827 20:19:26.373046 445 storage/replica_command.go:298  [split,n1,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180827 20:19:26.400851 532 server/server_update.go:67  [n1] no need to upgrade, cluster already at the newest version
I180827 20:19:26.438045 534 sql/event_log.go:126  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:39605} Attrs: Locality: ServerVersion:2.0-12 BuildTag:v2.1.0-alpha.20180702-2029-g9781d76 StartedAt:1535401164962835637 LocalityAddress:[]} ClusterID:11dfb876-012b-4855-8cf1-8c567d94bb72 StartedAt:1535401164962835637 LastUp:1535401164962835637}
I180827 20:19:26.447435 537 storage/replica_command.go:298  [split,n1,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180827 20:19:26.495009 512 storage/replica_command.go:298  [split,n1,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180827 20:19:26.547542 594 storage/replica_command.go:298  [split,n1,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180827 20:19:26.592674 589 storage/replica_command.go:298  [split,n1,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180827 20:19:26.687607 606 storage/replica_command.go:298  [split,n1,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180827 20:19:26.753801 632 storage/replica_command.go:298  [split,n1,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180827 20:19:26.788938 521 storage/replica_command.go:298  [split,n1,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
I180827 20:19:27.151823 559 storage/replica_command.go:298  [split,n1,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/52 [r23]
I180827 20:19:27.162092 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_table", target: 52, info: {TableName:defaultdb.public.blah Statement:CREATE TABLE blah (i INT) User:root}
I180827 20:19:27.177511 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root] publish: descID=52 (blah) version=2 mtime=2018-08-27 20:19:27.163185885 +0000 UTC
I180827 20:19:27.227744 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_table", target: 52, info: {TableName:defaultdb.public.blah Statement:DROP TABLE blah User:root CascadeDroppedViews:[]}
I180827 20:19:27.304490 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root,scExec=] publish: descID=52 (blah) version=3 mtime=2018-08-27 20:19:27.303228331 +0000 UTC
--- FAIL: testrace/TestImportData/PGDUMP:_semicolons_and_comments (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:54.694580 244 storage/replica_proposal.go:211  [n1,s1,r100/1:/{Table/114-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:54.801802 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 116, info: {DatabaseName:d32 Statement:CREATE DATABASE d32 User:root}
I180827 20:19:54.813678 4654 storage/replica_command.go:298  [split,n1,s1,r101/1:/{Table/115-Max}] initiating a split of this range at key /Table/116 [r102]
I180827 20:19:54.878283 188 storage/replica_proposal.go:211  [n1,s1,r101/1:/{Table/115-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:55.007631 290 server/status/runtime.go:433  [n1] runtime stats: 427 MiB RSS, 471 goroutines, 26 MiB/1.9 MiB/41 MiB GO alloc/idle/total, 68 MiB/88 MiB CGO alloc/total, 3096.51cgo/sec, 1.19/0.05 %(u/s)time, 0.01 %gc (10x)
I180827 20:19:55.077531 4657 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:55.136567 230 storage/replica_proposal.go:211  [n1,s1,r15/1:/Table/1{8-9}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401195.127592709,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:19:55.291970 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:19:55.328195 4775 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:55.737163 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root] publish: descID=117 (t) version=2 mtime=2018-08-27 20:19:55.728534683 +0000 UTC
I180827 20:19:55.825066 4713 storage/replica_command.go:298  [split,n1,s1,r102/1:/{Table/116-Max}] initiating a split of this range at key /Table/117 [r103]
I180827 20:19:55.840323 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 116, info: {DatabaseName:d32 Statement:DROP DATABASE d32 User:root DroppedSchemaObjects:[d32.public.t]}
I180827 20:19:55.945624 185 storage/replica_proposal.go:211  [n1,s1,r102/1:/{Table/116-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:55.984341 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root,scExec=] publish: descID=117 (t) version=3 mtime=2018-08-27 20:19:55.983088058 +0000 UTC
--- FAIL: testrace/TestImportData/CSV:_duplicate_PK (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:28.100728 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 55, info: {DatabaseName:d1 Statement:CREATE DATABASE d1 User:root}
I180827 20:19:28.107067 867 storage/replica_command.go:298  [split,n1,s1,r25/1:/{Table/54-Max}] initiating a split of this range at key /Table/55 [r26]
I180827 20:19:28.312398 875 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:28.455960 842 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
W180827 20:19:28.584836 293 sql/schema_changer.go:1304  [n1] Error executing schema change: descriptor not found
I180827 20:19:28.621832 938 storage/replica_command.go:298  [split,n1,s1,r26/1:/{Table/55-Max}] initiating a split of this range at key /Table/56 [r27]
I180827 20:19:28.709231 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 55, info: {DatabaseName:d1 Statement:DROP DATABASE d1 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData/PGDUMP:_size_out_of_range (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:56.143137 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 118, info: {DatabaseName:d33 Statement:CREATE DATABASE d33 User:root}
I180827 20:19:56.154494 4830 storage/replica_command.go:298  [split,n1,s1,r103/1:/{Table/117-Max}] initiating a split of this range at key /Table/118 [r104]
I180827 20:19:56.229970 235 storage/replica_proposal.go:211  [n1,s1,r103/1:/{Table/117-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:56.263486 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 118, info: {DatabaseName:d33 Statement:DROP DATABASE d33 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData/PGCOPY:_escapes (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:47.338830 201 storage/replica_proposal.go:211  [n1,s1,r80/1:/{Table/97-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:47.400073 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 99, info: {DatabaseName:d23 Statement:CREATE DATABASE d23 User:root}
I180827 20:19:47.413604 3736 storage/replica_command.go:298  [split,n1,s1,r81/1:/{Table/98-Max}] initiating a split of this range at key /Table/99 [r82]
I180827 20:19:47.511731 246 storage/replica_proposal.go:211  [n1,s1,r81/1:/{Table/98-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:47.650881 3826 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:47.784844 3820 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:47.820531 3824 storage/replica_command.go:298  [n1,s1,r82/1:/{Table/99-Max}] initiating a split of this range at key /Table/101 [r83]
I180827 20:19:47.895098 251 storage/replica_proposal.go:211  [n1,s1,r82/1:/{Table/99-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:48.067337 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root] publish: descID=100 (t) version=2 mtime=2018-08-27 20:19:48.059478766 +0000 UTC
I180827 20:19:48.161371 3792 storage/replica_command.go:298  [split,n1,s1,r82/1:/Table/{99-101}] initiating a split of this range at key /Table/100 [r84]
I180827 20:19:48.208340 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 99, info: {DatabaseName:d23 Statement:DROP DATABASE d23 User:root DroppedSchemaObjects:[d23.public.t]}
I180827 20:19:48.282545 226 storage/replica_proposal.go:211  [n1,s1,r82/1:/Table/{99-101}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:48.298857 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root,scExec=] publish: descID=100 (t) version=3 mtime=2018-08-27 20:19:48.297604787 +0000 UTC
I180827 20:19:48.378169 3881 storage/replica_command.go:430  [merge,n1,s1,r84/1:/Table/10{0-1}] initiating a merge of r83:/{Table/101-Max} [(n1,s1):1, next=2, gen=0] into this range
I180827 20:19:48.434166 230 storage/store.go:2642  [n1,s1,r84/1:/Table/10{0-1}] removing replica r83/1
--- FAIL: testrace/TestImportData/PGCOPY:_size_out_of_range (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:51.253821 186 storage/store.go:2642  [n1,s1,r90/1:/Table/10{4-5}] removing replica r89/1
I180827 20:19:51.289941 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 105, info: {DatabaseName:d26 Statement:CREATE DATABASE d26 User:root}
I180827 20:19:51.302804 4141 storage/replica_command.go:298  [split,n1,s1,r90/1:/{Table/104-Max}] initiating a split of this range at key /Table/105 [r91]
I180827 20:19:51.381335 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 105, info: {DatabaseName:d26 Statement:DROP DATABASE d26 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData/PGDUMP:_fk-skip (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:20:03.701499 5623 storage/replica_command.go:298  [split,n1,s1,r118/1:/{Table/131-Max}] initiating a split of this range at key /Table/132 [r121]
I180827 20:20:03.726596 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 132, info: {DatabaseName:d40 Statement:CREATE DATABASE d40 User:root}
I180827 20:20:03.857607 203 storage/replica_proposal.go:211  [n1,s1,r118/1:/{Table/131-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:20:04.028147 5648 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:20:04.152321 182 storage/replica_proposal.go:211  [n1,s1,r37/1:/Table/6{3-4}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401204.148832061,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:04.227976 5740 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:20:04.294307 5795 storage/replica_command.go:298  [n1,s1,r121/1:/{Table/132-Max}] initiating a split of this range at key /Table/134 [r122]
I180827 20:20:04.348094 200 storage/replica_proposal.go:211  [n1,s1,r121/1:/{Table/132-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:20:04.483521 5811 storage/replica_command.go:298  [n1,s1,r122/1:/{Table/134-Max}] initiating a split of this range at key /Table/135 [r123]
I180827 20:20:04.532936 209 storage/replica_proposal.go:211  [n1,s1,r122/1:/{Table/134-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:20:04.843980 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root] publish: descID=133 (cities) version=2 mtime=2018-08-27 20:20:04.831124656 +0000 UTC
I180827 20:20:04.854743 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root] publish: descID=134 (weather) version=2 mtime=2018-08-27 20:20:04.831124656 +0000 UTC
I180827 20:20:04.966606 5817 storage/replica_command.go:298  [split,n1,s1,r121/1:/Table/13{2-4}] initiating a split of this range at key /Table/133 [r124]
I180827 20:20:04.998399 290 server/status/runtime.go:433  [n1] runtime stats: 469 MiB RSS, 557 goroutines, 19 MiB/7.0 MiB/44 MiB GO alloc/idle/total, 74 MiB/96 MiB CGO alloc/total, 2558.60cgo/sec, 1.18/0.05 %(u/s)time, 0.00 %gc (10x)
I180827 20:20:05.012941 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 132, info: {DatabaseName:d40 Statement:DROP DATABASE d40 User:root DroppedSchemaObjects:[d40.public.cities d40.public.weather]}
I180827 20:20:05.016639 5820 storage/replica_command.go:430  [merge,n1,s1,r122/1:/Table/13{4-5}] initiating a merge of r123:/{Table/135-Max} [(n1,s1):1, next=2, gen=0] into this range
I180827 20:20:05.122274 190 storage/replica_proposal.go:211  [n1,s1,r121/1:/Table/13{2-4}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:20:05.194124 204 storage/replica_proposal.go:211  [n1,s1,r28/1:/Table/5{7-8}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401205.150217479,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:05.230025 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root,scExec=] publish: descID=133 (cities) version=3 mtime=2018-08-27 20:20:05.228817158 +0000 UTC
I180827 20:20:05.239152 233 storage/store.go:2642  [n1,s1,r122/1:/Table/13{4-5}] removing replica r123/1
I180827 20:20:05.292757 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:20:05.434210 556 sql/lease.go:345  [n1,client=127.0.0.1:34890,user=root,scExec=] publish: descID=134 (weather) version=3 mtime=2018-08-27 20:20:05.432835994 +0000 UTC
--- FAIL: testrace/TestImportData/PGDUMP:_mismatch_cols (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:53.482166 244 storage/replica_proposal.go:211  [n1,s1,r96/1:/{Table/110-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:53.526974 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 112, info: {DatabaseName:d30 Statement:CREATE DATABASE d30 User:root}
I180827 20:19:53.566143 4509 storage/replica_command.go:298  [split,n1,s1,r97/1:/{Table/111-Max}] initiating a split of this range at key /Table/112 [r98]
I180827 20:19:53.671207 185 storage/replica_proposal.go:211  [n1,s1,r97/1:/{Table/111-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:53.744896 4584 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:53.939190 4591 storage/replica_command.go:298  [split,n1,s1,r98/1:/{Table/112-Max}] initiating a split of this range at key /Table/113 [r99]
W180827 20:19:53.979133 293 sql/schema_changer.go:1304  [n1] Error executing schema change: descriptor not found
I180827 20:19:54.006626 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 112, info: {DatabaseName:d30 Statement:DROP DATABASE d30 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData/PGCOPY:_not_enough_values (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:52.091418 238 storage/replica_proposal.go:211  [n1,s1,r92/1:/{Table/106-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:52.096442 209 storage/replica_proposal.go:211  [n1,s1,r13/1:/Table/1{6-7}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401192.082770562,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:19:52.163472 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 108, info: {DatabaseName:d28 Statement:CREATE DATABASE d28 User:root}
I180827 20:19:52.197833 4331 storage/replica_command.go:298  [split,n1,s1,r93/1:/{Table/107-Max}] initiating a split of this range at key /Table/108 [r94]
I180827 20:19:52.287196 190 storage/replica_proposal.go:211  [n1,s1,r93/1:/{Table/107-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:52.376533 4255 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:52.551335 4428 storage/replica_command.go:298  [split,n1,s1,r94/1:/{Table/108-Max}] initiating a split of this range at key /Table/109 [r95]
I180827 20:19:52.641693 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 108, info: {DatabaseName:d28 Statement:DROP DATABASE d28 User:root DroppedSchemaObjects:[]}
--- FAIL: testrace/TestImportData/MYSQLOUTFILE:_unmatched_literal (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:19:39.275724 2723 storage/replica_command.go:298  [split,n1,s1,r59/1:/{Table/80-Max}] initiating a split of this range at key /Table/81 [r60]
I180827 20:19:39.284801 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 81, info: {DatabaseName:d14 Statement:CREATE DATABASE d14 User:root}
I180827 20:19:39.385877 191 storage/replica_proposal.go:211  [n1,s1,r59/1:/{Table/80-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
I180827 20:19:39.551214 2669 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:19:39.671617 2697 storage/replica_command.go:298  [split,n1,s1,r60/1:/{Table/81-Max}] initiating a split of this range at key /Table/82 [r61]
I180827 20:19:39.732286 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "drop_database", target: 81, info: {DatabaseName:d14 Statement:DROP DATABASE d14 User:root DroppedSchemaObjects:[]}
I180827 20:19:39.739514 252 storage/replica_proposal.go:211  [n1,s1,r60/1:/{Table/81-Max}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0 following repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401173.551880905,0
--- FAIL: testrace/TestImportData/TABLE_weather_FROM_PGDUMP:_fk_unreferenced_skipped (0.000s)
Test ended in panic.

------- Stdout: -------
I180827 20:20:05.879101 5856 storage/replica_command.go:430  [merge,n1,s1,r122/1:/Table/13{4-5}] initiating a merge of r125:/{Table/135-Max} [(n1,s1):1, next=2, gen=0] into this range
I180827 20:20:05.902314 5889 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r126]
I180827 20:20:05.930402 556 sql/event_log.go:126  [n1,client=127.0.0.1:34890,user=root] Event: "create_database", target: 136, info: {DatabaseName:d42 Statement:CREATE DATABASE d42 User:root}
I180827 20:20:06.156117 256 storage/replica_proposal.go:211  [n1,s1,r18/1:/Table/2{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401206.152069781,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:06.264457 5965 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:20:06.421877 6002 ccl/importccl/read_import_proc.go:74  [n1,import-distsql] could not fetch file size; falling back to per-file progress: bad ContentLength: -1
I180827 20:20:06.470875 5994 storage/replica_command.go:298  [n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/138 [r127]
I180827 20:20:07.157898 226 storage/replica_proposal.go:211  [n1,s1,r25/1:/Table/5{4-5}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401207.153853586,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:08.158697 200 storage/replica_proposal.go:211  [n1,s1,r32/1:/Table/6{1-2}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401208.155325252,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:09.160502 208 storage/replica_proposal.go:211  [n1,s1,r30/1:/Table/{59-60}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401209.156756003,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:10.162149 253 storage/replica_proposal.go:211  [n1,s1,r19/1:/Table/2{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401210.158306280,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:12.164972 232 storage/replica_proposal.go:211  [n1,s1,r29/1:/Table/5{8-9}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401212.161453797,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:14.172784 258 storage/replica_proposal.go:211  [n1,s1,r23/1:/Table/5{2-3}] new range lease repl=(n1,s1):1 seq=3 start=1535401164.968394090,0 epo=1 pro=1535401214.169205484,0 following repl=(n1,s1):1 seq=2 start=1535401164.968394090,0 exp=1535401173.986694367,0 pro=1535401164.986834663,0
I180827 20:20:15.020070 290 server/status/runtime.go:433  [n1] runtime stats: 493 MiB RSS, 580 goroutines, 24 MiB/5.3 MiB/49 MiB GO alloc/idle/total, 76 MiB/97 MiB CGO alloc/total, 447.95cgo/sec, 0.48/0.02 %(u/s)time, 0.00 %gc (3x)
I180827 20:20:15.292066 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:20:24.995977 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:20:25.005381 290 server/status/runtime.go:433  [n1] runtime stats: 496 MiB RSS, 580 goroutines, 28 MiB/2.0 MiB/49 MiB GO alloc/idle/total, 76 MiB/98 MiB CGO alloc/total, 53.84cgo/sec, 0.35/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:20:25.292013 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:20:34.998432 290 server/status/runtime.go:433  [n1] runtime stats: 501 MiB RSS, 580 goroutines, 20 MiB/11 MiB/50 MiB GO alloc/idle/total, 76 MiB/98 MiB CGO alloc/total, 58.04cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:20:35.292056 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
W180827 20:20:36.047001 5959 storage/intent_resolver.go:738  [n1,s1] failed to cleanup transaction intents: failed to resolve intents: the batch experienced mixed success and failure
I180827 20:20:45.008013 290 server/status/runtime.go:433  [n1] runtime stats: 502 MiB RSS, 579 goroutines, 25 MiB/7.1 MiB/51 MiB GO alloc/idle/total, 80 MiB/101 MiB CGO alloc/total, 56.35cgo/sec, 0.31/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:20:45.292078 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:20:55.001141 290 server/status/runtime.go:433  [n1] runtime stats: 507 MiB RSS, 579 goroutines, 27 MiB/4.8 MiB/51 MiB GO alloc/idle/total, 79 MiB/101 MiB CGO alloc/total, 54.34cgo/sec, 0.30/0.01 %(u/s)time, 0.00 %gc (2x)
I180827 20:20:55.292102 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:21:05.006220 290 server/status/runtime.go:433  [n1] runtime stats: 514 MiB RSS, 579 goroutines, 26 MiB/7.2 MiB/52 MiB GO alloc/idle/total, 79 MiB/101 MiB CGO alloc/total, 46.48cgo/sec, 0.37/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:21:05.292001 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:21:05.903477 5889 storage/queue.go:788  [split,n1,s1,r125/1:/{Table/135-Max}] unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded
I180827 20:21:15.018792 290 server/status/runtime.go:433  [n1] runtime stats: 515 MiB RSS, 578 goroutines, 27 MiB/6.6 MiB/52 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 47.64cgo/sec, 0.25/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:21:15.292022 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:21:18.291254 6291 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r128]
I180827 20:21:25.000137 290 server/status/runtime.go:433  [n1] runtime stats: 515 MiB RSS, 582 goroutines, 30 MiB/4.6 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 28.75cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:21:25.002942 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:21:25.292018 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:21:35.031027 290 server/status/runtime.go:433  [n1] runtime stats: 516 MiB RSS, 581 goroutines, 23 MiB/11 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 21.53cgo/sec, 0.32/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:21:35.292039 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:21:44.998081 290 server/status/runtime.go:433  [n1] runtime stats: 520 MiB RSS, 581 goroutines, 18 MiB/15 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 43.84cgo/sec, 0.33/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:21:45.292135 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:21:55.012434 290 server/status/runtime.go:433  [n1] runtime stats: 521 MiB RSS, 583 goroutines, 23 MiB/11 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 27.86cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:21:55.292039 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:22:05.004232 290 server/status/runtime.go:433  [n1] runtime stats: 521 MiB RSS, 581 goroutines, 19 MiB/15 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 21.32cgo/sec, 0.22/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:22:05.292254 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:22:05.869544 6246 storage/queue.go:788  [merge,n1,s1,r122/1:/Table/13{4-5}] context deadline exceeded
I180827 20:22:05.869861 6246 storage/queue.go:873  [n1,merge] purgatory is now empty
I180827 20:22:15.008351 290 server/status/runtime.go:433  [n1] runtime stats: 521 MiB RSS, 580 goroutines, 29 MiB/5.0 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 18.69cgo/sec, 0.21/0.00 %(u/s)time, 0.00 %gc (1x)
I180827 20:22:15.292084 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:22:18.292116 6291 storage/queue.go:788  [split,n1,s1,r125/1:/{Table/135-Max}] unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded
I180827 20:22:18.293371 6370 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r129]
E180827 20:22:18.295511 6256 storage/consistency_queue.go:125  [consistencyChecker,n1,s1,r125/1:/{Table/135-Max}] context deadline exceeded
E180827 20:22:18.295719 6256 storage/queue.go:788  [consistencyChecker,n1,s1,r125/1:/{Table/135-Max}] context deadline exceeded
I180827 20:22:25.002175 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:22:25.008882 290 server/status/runtime.go:433  [n1] runtime stats: 521 MiB RSS, 582 goroutines, 24 MiB/10 MiB/53 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 21.80cgo/sec, 0.35/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:22:25.292073 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:22:34.996575 290 server/status/runtime.go:433  [n1] runtime stats: 523 MiB RSS, 581 goroutines, 29 MiB/6.2 MiB/54 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 26.23cgo/sec, 0.30/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:22:35.292118 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:22:45.015531 290 server/status/runtime.go:433  [n1] runtime stats: 527 MiB RSS, 581 goroutines, 31 MiB/4.2 MiB/54 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 16.47cgo/sec, 0.27/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:22:45.292044 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:22:55.018032 290 server/status/runtime.go:433  [n1] runtime stats: 531 MiB RSS, 581 goroutines, 31 MiB/5.0 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 16.30cgo/sec, 0.27/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:22:55.291970 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:23:05.003989 290 server/status/runtime.go:433  [n1] runtime stats: 532 MiB RSS, 581 goroutines, 32 MiB/4.1 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 18.63cgo/sec, 0.27/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:23:05.292139 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:23:15.000937 290 server/status/runtime.go:433  [n1] runtime stats: 532 MiB RSS, 581 goroutines, 24 MiB/12 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 19.91cgo/sec, 0.20/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:23:15.292097 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:23:18.294215 6370 storage/queue.go:788  [split,n1,s1,r125/1:/{Table/135-Max}] unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded
I180827 20:23:24.998884 290 server/status/runtime.go:433  [n1] runtime stats: 533 MiB RSS, 582 goroutines, 33 MiB/3.4 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 19.70cgo/sec, 0.19/0.00 %(u/s)time, 0.00 %gc (1x)
I180827 20:23:25.009198 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:23:25.292289 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:23:34.997781 290 server/status/runtime.go:433  [n1] runtime stats: 538 MiB RSS, 581 goroutines, 23 MiB/14 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 21.50cgo/sec, 0.33/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:23:35.292093 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:23:45.028199 290 server/status/runtime.go:433  [n1] runtime stats: 538 MiB RSS, 581 goroutines, 35 MiB/2.4 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 14.76cgo/sec, 0.35/0.00 %(u/s)time, 0.01 %gc (2x)
I180827 20:23:45.292055 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:23:55.004987 290 server/status/runtime.go:433  [n1] runtime stats: 539 MiB RSS, 581 goroutines, 26 MiB/12 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 16.35cgo/sec, 0.33/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:23:55.292170 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:05.015560 290 server/status/runtime.go:433  [n1] runtime stats: 539 MiB RSS, 581 goroutines, 28 MiB/8.7 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 23.87cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:24:05.292467 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:15.003340 290 server/status/runtime.go:433  [n1] runtime stats: 539 MiB RSS, 581 goroutines, 32 MiB/5.1 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 16.31cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:24:15.292132 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:24.994809 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:24:25.000073 290 server/status/runtime.go:433  [n1] runtime stats: 540 MiB RSS, 582 goroutines, 36 MiB/1.8 MiB/56 MiB GO alloc/idle/total, 79 MiB/102 MiB CGO alloc/total, 32.11cgo/sec, 0.30/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:24:25.292075 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:35.005992 290 server/status/runtime.go:433  [n1] runtime stats: 542 MiB RSS, 581 goroutines, 36 MiB/2.7 MiB/58 MiB GO alloc/idle/total, 78 MiB/102 MiB CGO alloc/total, 20.09cgo/sec, 0.27/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:24:35.318151 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:45.005538 290 server/status/runtime.go:433  [n1] runtime stats: 548 MiB RSS, 581 goroutines, 28 MiB/10 MiB/58 MiB GO alloc/idle/total, 86 MiB/110 MiB CGO alloc/total, 20.00cgo/sec, 0.35/0.01 %(u/s)time, 0.00 %gc (3x)
I180827 20:24:45.292172 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:24:55.007786 290 server/status/runtime.go:433  [n1] runtime stats: 548 MiB RSS, 581 goroutines, 33 MiB/5.6 MiB/58 MiB GO alloc/idle/total, 86 MiB/110 MiB CGO alloc/total, 16.30cgo/sec, 0.31/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:24:55.292093 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:05.012613 290 server/status/runtime.go:433  [n1] runtime stats: 548 MiB RSS, 581 goroutines, 36 MiB/2.5 MiB/58 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 18.59cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:25:05.292140 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:15.028748 290 server/status/runtime.go:433  [n1] runtime stats: 553 MiB RSS, 581 goroutines, 23 MiB/16 MiB/59 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.17cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:25:15.292133 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:24.797678 6535 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r130]
I180827 20:25:24.996678 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:25:25.001979 290 server/status/runtime.go:433  [n1] runtime stats: 554 MiB RSS, 583 goroutines, 27 MiB/12 MiB/59 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 21.36cgo/sec, 0.30/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:25:25.292818 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:35.003455 290 server/status/runtime.go:433  [n1] runtime stats: 554 MiB RSS, 583 goroutines, 34 MiB/5.4 MiB/59 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 39.29cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:25:35.292080 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:44.999640 290 server/status/runtime.go:433  [n1] runtime stats: 554 MiB RSS, 583 goroutines, 26 MiB/13 MiB/59 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 17.21cgo/sec, 0.36/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:25:45.292099 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:25:55.019259 290 server/status/runtime.go:433  [n1] runtime stats: 554 MiB RSS, 583 goroutines, 26 MiB/12 MiB/59 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.27cgo/sec, 0.29/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:25:55.292061 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:26:05.002635 290 server/status/runtime.go:433  [n1] runtime stats: 562 MiB RSS, 583 goroutines, 34 MiB/7.6 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 20.33cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:26:05.292043 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:26:15.004113 290 server/status/runtime.go:433  [n1] runtime stats: 565 MiB RSS, 583 goroutines, 26 MiB/15 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 19.90cgo/sec, 0.38/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:26:15.292171 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:26:24.798613 6535 storage/queue.go:788  [split,n1,s1,r125/1:/{Table/135-Max}] unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded
I180827 20:26:24.999022 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:26:25.011059 290 server/status/runtime.go:433  [n1] runtime stats: 565 MiB RSS, 583 goroutines, 35 MiB/6.2 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.98cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:26:25.292401 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:26:35.022894 290 server/status/runtime.go:433  [n1] runtime stats: 565 MiB RSS, 583 goroutines, 36 MiB/5.2 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 20.08cgo/sec, 0.32/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:26:35.292061 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:26:38.955190 6575 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r131]
I180827 20:26:45.009423 290 server/status/runtime.go:433  [n1] runtime stats: 565 MiB RSS, 585 goroutines, 25 MiB/15 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.62cgo/sec, 0.37/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:26:45.292103 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:26:55.022993 290 server/status/runtime.go:433  [n1] runtime stats: 568 MiB RSS, 585 goroutines, 34 MiB/7.2 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 28.89cgo/sec, 0.35/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:26:55.292045 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:27:05.011973 290 server/status/runtime.go:433  [n1] runtime stats: 568 MiB RSS, 585 goroutines, 25 MiB/15 MiB/61 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 22.20cgo/sec, 0.52/0.00 %(u/s)time, 0.00 %gc (4x)
I180827 20:27:05.292232 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:27:15.014209 290 server/status/runtime.go:433  [n1] runtime stats: 570 MiB RSS, 585 goroutines, 28 MiB/14 MiB/62 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 15.40cgo/sec, 0.33/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:27:15.292130 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:27:24.995275 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:27:25.011101 290 server/status/runtime.go:433  [n1] runtime stats: 573 MiB RSS, 586 goroutines, 27 MiB/14 MiB/62 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 21.21cgo/sec, 0.30/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:27:25.292094 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:27:35.014511 290 server/status/runtime.go:433  [n1] runtime stats: 574 MiB RSS, 585 goroutines, 28 MiB/14 MiB/62 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 19.99cgo/sec, 0.31/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:27:35.292174 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
E180827 20:27:38.959576 6575 storage/queue.go:788  [split,n1,s1,r125/1:/{Table/135-Max}] unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded
I180827 20:27:45.013686 290 server/status/runtime.go:433  [n1] runtime stats: 574 MiB RSS, 585 goroutines, 31 MiB/11 MiB/62 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 18.30cgo/sec, 0.31/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:27:45.292151 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:27:55.018402 290 server/status/runtime.go:433  [n1] runtime stats: 577 MiB RSS, 585 goroutines, 35 MiB/7.8 MiB/63 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.30cgo/sec, 0.34/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:27:55.292068 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:05.008231 290 server/status/runtime.go:433  [n1] runtime stats: 581 MiB RSS, 585 goroutines, 42 MiB/2.2 MiB/64 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 20.21cgo/sec, 0.36/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:28:05.292045 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:15.007012 290 server/status/runtime.go:433  [n1] runtime stats: 583 MiB RSS, 585 goroutines, 35 MiB/9.3 MiB/64 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 18.81cgo/sec, 0.27/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:28:15.292088 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:24.996440 47 gossip/gossip.go:537  [n1] gossip status (ok, 1 node)
gossip client (0/3 cur/max conns)
gossip server (0/3 cur/max conns, infos 0/0 sent/received, bytes 0B/0B sent/received)
I180827 20:28:25.009271 290 server/status/runtime.go:433  [n1] runtime stats: 586 MiB RSS, 587 goroutines, 35 MiB/9.0 MiB/64 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 17.19cgo/sec, 0.31/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:28:25.292036 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:35.005136 290 server/status/runtime.go:433  [n1] runtime stats: 586 MiB RSS, 585 goroutines, 23 MiB/20 MiB/64 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 25.91cgo/sec, 0.36/0.00 %(u/s)time, 0.00 %gc (3x)
I180827 20:28:35.292138 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:45.065233 290 server/status/runtime.go:433  [n1] runtime stats: 586 MiB RSS, 585 goroutines, 37 MiB/7.0 MiB/64 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.40cgo/sec, 0.25/0.00 %(u/s)time, 0.00 %gc (1x)
I180827 20:28:45.292027 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:28:53.226377 6760 storage/replica_command.go:298  [split,n1,s1,r125/1:/{Table/135-Max}] initiating a split of this range at key /Table/136 [r132]
I180827 20:28:55.005310 290 server/status/runtime.go:433  [n1] runtime stats: 596 MiB RSS, 587 goroutines, 32 MiB/15 MiB/67 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 16.50cgo/sec, 0.30/0.00 %(u/s)time, 0.00 %gc (2x)
I180827 20:28:55.292050 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:29:05.004602 290 server/status/runtime.go:433  [n1] runtime stats: 596 MiB RSS, 587 goroutines, 38 MiB/8.8 MiB/67 MiB GO alloc/idle/total, 94 MiB/118 MiB CGO alloc/total, 21.10cgo/sec, 0.21/0.00 %(u/s)time, 0.00 %gc (1x)
I180827 20:29:05.292087 292 server/status/recorder.go:652  [n1,summaries] available memory from cgroups (8.0 EiB) exceeds system memory 16 GiB, using system memory
I180827 20:29:15.012219 290 server/status/runtime.go:433  [n1] runtime stats: 597 MiB RSS

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

maddyblue commented 5 years ago

This has "unable to split [n1,s1,r125/1:/{Table/135-Max}] at key "/Table/136": split at key /Table/136 failed: context deadline exceeded". I think some split bugs were fixed recently? Closing anyway because this hasn't happened in a long time.