Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

teamcity: failed tests on master: test/TestBackupRestoreInterleaved, test/TestBackupRestoreInterleaved/all_tables_in_interleave_hierarchy, testrace/TestBackupRestoreInterleaved, testrace/TestBackupRestoreInterleaved/all_tables_in_interleave_hierarchy #21378

Closed
cockroach-teamcity opened this issue Jan 10, 2018 · 1 comment
Closed

teamcity: failed tests on master: test/TestBackupRestoreInterleaved, test/TestBackupRestoreInterleaved/all_tables_in_interleave_hierarchy, testrace/TestBackupRestoreInterleaved, testrace/TestBackupRestoreInterleaved/all_tables_in_interleave_hierarchy #21378

cockroach-teamcity opened this issue Jan 10, 2018 · 1 comment
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.

Comments

@cockroach-teamcity
Copy link
Member

The following tests appear to have failed:

#474455:

--- FAIL: test/TestBackupRestoreInterleaved (0.000s)
Test ended in panic.

------- Stdout: -------
W180110 18:02:59.680952 118774 server/status/runtime.go:109  Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180110 18:02:59.682776 118774 server/config.go:518  [n?] 1 storage engine initialized
I180110 18:02:59.682793 118774 server/config.go:521  [n?] RocksDB cache size: 128 MiB
I180110 18:02:59.682798 118774 server/config.go:521  [n?] store 0: in-memory, size 0 B
I180110 18:02:59.684988 118774 server/node.go:361  [n?] **** cluster 12dcf5c1-311b-4753-a474-73554bd7f94f has been created
I180110 18:02:59.685014 118774 server/server.go:934  [n?] **** add additional nodes by specifying --join=127.0.0.1:35537
I180110 18:02:59.685616 118774 storage/store.go:1312  [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available
I180110 18:02:59.685656 118774 server/node.go:491  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=3.2 KiB), ranges=1, leases=0, writes=0.00, bytesPerReplica={p10=3322.00 p25=3322.00 p50=3322.00 p75=3322.00 p90=3322.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00}
I180110 18:02:59.685688 118774 server/node.go:339  [n1] node ID 1 initialized
I180110 18:02:59.685757 118774 gossip/gossip.go:332  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:35537" > attrs:<> locality:<> ServerVersion:<major_val:1 minor_val:1 patch:0 unstable:9 > 
I180110 18:02:59.685924 118774 storage/stores.go:331  [n1] read 0 node addresses from persistent storage
I180110 18:02:59.686060 118774 server/node.go:632  [n1] connecting to gossip network to verify cluster ID...
I180110 18:02:59.686094 118774 server/node.go:657  [n1] node connected via gossip and verified as part of cluster "12dcf5c1-311b-4753-a474-73554bd7f94f"
I180110 18:02:59.686121 118774 server/node.go:433  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180110 18:02:59.686252 118774 sql/distsql_physical_planner.go:122  [n1] creating DistSQLPlanner with address {tcp 127.0.0.1:35537}
I180110 18:02:59.687294 118745 storage/replica_command.go:819  [split,n1,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180110 18:02:59.693580 118774 server/server.go:1161  [n1] starting https server at 127.0.0.1:40697
I180110 18:02:59.693633 118774 server/server.go:1162  [n1] starting grpc/postgres server at 127.0.0.1:35537
I180110 18:02:59.693657 118774 server/server.go:1163  [n1] advertising CockroachDB node at 127.0.0.1:35537
I180110 18:02:59.698407 118745 storage/replica_command.go:819  [split,n1,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
I180110 18:02:59.703687 118745 storage/replica_command.go:819  [split,n1,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
W180110 18:02:59.704283 119042 storage/intent_resolver.go:324  [n1,s1] failed to push during intent resolution: failed to push "sql txn implicit" id=96eef510 key=/Table/SystemConfigSpan/Start rw=true pri=0.03373129 iso=SERIALIZABLE stat=PENDING epo=0 ts=1515607379.699252305,0 orig=1515607379.699252305,0 max=1515607379.699252305,0 wto=false rop=false seq=7
I180110 18:02:59.705378 118774 sql/event_log.go:115  [n1] Event: "alter_table", target: 12, info: {TableName:eventlog Statement:ALTER TABLE system.eventlog ALTER COLUMN "uniqueID" SET DEFAULT uuid_v4() User:node MutationID:0 CascadeDroppedViews:[]}
I180110 18:02:59.709553 118745 storage/replica_command.go:819  [split,n1,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180110 18:02:59.711655 118774 sql/lease.go:348  [n1] publish: descID=12 (eventlog) version=2 mtime=2018-01-10 18:02:59.711397351 +0000 UTC
I180110 18:02:59.714515 118745 storage/replica_command.go:819  [split,n1,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
I180110 18:02:59.722104 118745 storage/replica_command.go:819  [split,n1,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180110 18:02:59.728036 118745 storage/replica_command.go:819  [split,n1,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
W180110 18:02:59.728476 118812 storage/intent_resolver.go:324  [n1,s1] failed to push during intent resolution: failed to push "sql txn implicit" id=f8a38c98 key=/Table/SystemConfigSpan/Start rw=true pri=0.00799806 iso=SERIALIZABLE stat=PENDING epo=0 ts=1515607379.723877453,0 orig=1515607379.723877453,0 max=1515607379.723877453,0 wto=false rop=false seq=7
I180110 18:02:59.729842 118774 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:node}
I180110 18:02:59.732898 118745 storage/replica_command.go:819  [split,n1,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180110 18:02:59.738942 118745 storage/replica_command.go:819  [split,n1,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180110 18:02:59.741515 118774 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:$1 User:node}
I180110 18:02:59.743707 118745 storage/replica_command.go:819  [split,n1,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180110 18:02:59.745378 118774 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:node}
I180110 18:02:59.748179 118745 storage/replica_command.go:819  [split,n1,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180110 18:02:59.754047 118745 storage/replica_command.go:819  [split,n1,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180110 18:02:59.756675 118774 sql/event_log.go:115  [n1] Event: "alter_table", target: 4, info: {TableName:users Statement:ALTER TABLE system.users ADD COLUMN IF NOT EXISTS "isRole" BOOL NOT NULL DEFAULT false User:node MutationID:1 CascadeDroppedViews:[]}
I180110 18:02:59.757649 118745 storage/replica_command.go:819  [split,n1,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180110 18:02:59.761927 118774 sql/lease.go:348  [n1] publish: descID=4 (users) version=2 mtime=2018-01-10 18:02:59.761827399 +0000 UTC
I180110 18:02:59.765394 118745 storage/replica_command.go:819  [split,n1,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180110 18:02:59.766836 118774 sql/lease.go:348  [n1] publish: descID=4 (users) version=3 mtime=2018-01-10 18:02:59.766683769 +0000 UTC
I180110 18:02:59.769003 118745 storage/replica_command.go:819  [split,n1,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180110 18:02:59.771316 118774 sql/backfill.go:133  [n1] Running backfill for "users", v=3, m=1
I180110 18:02:59.771931 118745 storage/replica_command.go:819  [split,n1,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180110 18:02:59.774793 118745 storage/replica_command.go:819  [split,n1,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180110 18:02:59.778046 118745 storage/replica_command.go:819  [split,n1,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180110 18:02:59.781235 118774 sql/lease.go:348  [n1] publish: descID=4 (users) version=4 mtime=2018-01-10 18:02:59.781034178 +0000 UTC
I180110 18:02:59.782374 118745 storage/replica_command.go:819  [split,n1,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180110 18:02:59.784585 118774 sql/event_log.go:115  [n1] Event: "finish_schema_change", target: 4, info: {MutationID:1}
I180110 18:02:59.785559 118774 sql/lease.go:274  publish (count leases): descID=4 name=users version=3 count=1
I180110 18:02:59.818441 118774 server/server.go:1232  [n1] done ensuring all necessary migrations have run
I180110 18:02:59.818491 118774 server/server.go:1235  [n1] serving sql connections
I180110 18:02:59.820529 119248 sql/event_log.go:115  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:35537} Attrs: Locality: ServerVersion:1.1-9} ClusterID:12dcf5c1-311b-4753-a474-73554bd7f94f StartedAt:1515607379686099339 LastUp:1515607379686099339}
I180110 18:02:59.835610 119285 sql/event_log.go:115  [client=127.0.0.1:59480,user=root,n1] Event: "create_database", target: 50, info: {DatabaseName:data Statement:CREATE DATABASE data User:root}
I180110 18:02:59.836073 118745 storage/replica_command.go:819  [split,n1,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180110 18:02:59.839557 119285 sql/event_log.go:115  [client=127.0.0.1:59480,user=root,n1] Event: "create_table", target: 51, info: {TableName:bank Statement:CREATE TABLE bank (id INT PRIMARY KEY, balance INT, payload STRING, FAMILY (id, balance, payload)) User:root}
I180110 18:02:59.840359 118745 storage/replica_command.go:819  [split,n1,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
I180110 18:02:59.842925 119285 storage/replica_command.go:819  [n1,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51/1/1 [r23]
I180110 18:02:59.894721 119285 storage/replica_command.go:819  [n1,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/51/1/1 [r24]
I180110 18:02:59.897970 119285 storage/replica_command.go:819  [n1,s1,r24/1:/{Table/51/1/1-Max}] initiating a split of this range at key /Table/51/1/2 [r25]
I180110 18:02:59.902866 119285 storage/replica_command.go:819  [n1,s1,r25/1:/{Table/51/1/2-Max}] initiating a split of this range at key /Table/51/1/3 [r26]
I180110 18:02:59.906764 119285 storage/replica_command.go:819  [n1,s1,r26/1:/{Table/51/1/3-Max}] initiating a split of this range at key /Table/51/1/4 [r27]
I180110 18:02:59.911998 119285 storage/replica_command.go:819  [n1,s1,r27/1:/{Table/51/1/4-Max}] initiating a split of this range at key /Table/51/1/5 [r28]
I180110 18:02:59.915310 119285 storage/replica_command.go:819  [n1,s1,r28/1:/{Table/51/1/5-Max}] initiating a split of this range at key /Table/51/1/6 [r29]
I180110 18:02:59.918539 119285 storage/replica_command.go:819  [n1,s1,r29/1:/{Table/51/1/6-Max}] initiating a split of this range at key /Table/51/1/7 [r30]
I180110 18:02:59.922686 119285 storage/replica_command.go:819  [n1,s1,r30/1:/{Table/51/1/7-Max}] initiating a split of this range at key /Table/51/1/8 [r31]
I180110 18:02:59.926944 119285 storage/replica_command.go:819  [n1,s1,r31/1:/{Table/51/1/8-Max}] initiating a split of this range at key /Table/51/1/9 [r32]
I180110 18:02:59.934885 119285 sql/event_log.go:115  [client=127.0.0.1:59480,user=root,n1] Event: "create_table", target: 52, info: {TableName:i0 Statement:CREATE TABLE i0 (a INT, b INT, PRIMARY KEY (a, b)) INTERLEAVE IN PARENT bank (a) User:root}
I180110 18:02:59.936802 118745 storage/replica_command.go:819  [split,n1,s1,r32/1:/{Table/51/1/9-Max}] initiating a split of this range at key /Table/52 [r33]
I180110 18:02:59.936960 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=52 (i0) version=2 mtime=2018-01-10 18:02:59.936866919 +0000 UTC
I180110 18:02:59.941868 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=51 (bank) version=2 mtime=2018-01-10 18:02:59.941755855 +0000 UTC
I180110 18:02:59.943463 119285 sql/lease.go:274  publish (count leases): descID=51 name=bank version=1 count=1
I180110 18:02:59.979049 119285 sql/event_log.go:115  [client=127.0.0.1:59480,user=root,n1] Event: "create_table", target: 53, info: {TableName:i0_0 Statement:CREATE TABLE i0_0 (a INT, b INT, c INT, PRIMARY KEY (a, b, c)) INTERLEAVE IN PARENT i0 (a, b) User:root}
I180110 18:02:59.979712 118745 storage/replica_command.go:819  [split,n1,s1,r33/1:/{Table/52-Max}] initiating a split of this range at key /Table/53 [r34]
I180110 18:02:59.983045 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=53 (i0_0) version=2 mtime=2018-01-10 18:02:59.982717895 +0000 UTC
I180110 18:02:59.987749 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=52 (i0) version=3 mtime=2018-01-10 18:02:59.987656881 +0000 UTC
I180110 18:02:59.996752 119285 sql/event_log.go:115  [client=127.0.0.1:59480,user=root,n1] Event: "create_table", target: 54, info: {TableName:i1 Statement:CREATE TABLE i1 (a INT, b INT, PRIMARY KEY (a, b)) INTERLEAVE IN PARENT bank (a) User:root}
I180110 18:02:59.997271 118745 storage/replica_command.go:819  [split,n1,s1,r34/1:/{Table/53-Max}] initiating a split of this range at key /Table/54 [r35]
I180110 18:02:59.998973 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=54 (i1) version=2 mtime=2018-01-10 18:02:59.998869144 +0000 UTC
I180110 18:03:00.005665 119285 sql/lease.go:348  [client=127.0.0.1:59480,user=root,n1] publish: descID=51 (bank) version=3 mtime=2018-01-10 18:03:00.00552806 +0000 UTC
I180110 18:03:00.006862 119285 sql/lease.go:274  publish (count leases): descID=51 name=bank version=2 count=1
I180110 18:03:00.070675 119285 storage/replica_command.go:819  [n1,s1,r22/1:/Table/51{-/1/1}] initiating a split of this range at key /Table/51/1/0/#/52/1/1 [r36]
I180110 18:03:00.076517 119285 storage/replica_command.go:819  [n1,s1,r36/1:/Table/51/1/{0/#/52…-1}] initiating a split of this range at key /Table/51/1/0/#/52/1/2 [r37]
I180110 18:03:00.080343 119285 storage/replica_command.go:819  [n1,s1,r24/1:/Table/51/1/{1-2}] initiating a split of this range at key /Table/51/1/1/#/52/1/1 [r38]
I180110 18:03:00.084681 119285 storage/replica_command.go:819  [n1,s1,r38/1:/Table/51/1/{1/#/52…-2}] initiating a split of this range at key /Table/51/1/1/#/52/1/2 [r39]
I180110 18:03:00.090001 119285 storage/replica_command.go:819  [n1,s1,r25/1:/Table/51/1/{2-3}] initiating a split of this range at key /Table/51/1/2/#/52/1/1 [r40]
I180110 18:03:00.093756 119285 storage/replica_command.go:819  [n1,s1,r40/1:/Table/51/1/{2/#/52…-3}] initiating a split of this range at key /Table/51/1/2/#/52/1/2 [r41]
I180110 18:03:00.096434 119285 storage/replica_command.go:819  [n1,s1,r26/1:/Table/51/1/{3-4}] initiating a split of this range at key /Table/51/1/3/#/52/1/1 [r42]
I180110 18:03:00.099404 119285 storage/replica_command.go:819  [n1,s1,r42/1:/Table/51/1/{3/#/52…-4}] initiating a split of this range at key /Table/51/1/3/#/52/1/2 [r43]
I180110 18:03:00.103815 119285 storage/replica_command.go:819  [n1,s1,r27/1:/Table/51/1/{4-5}] initiating a split of this range at key /Table/51/1/4/#/52/1/1 [r44]
I180110 18:03:00.107627 119285 storage/replica_command.go:819  [n1,s1,r44/1:/Table/51/1/{4/#/52…-5}] initiating a split of this range at key /Table/51/1/4/#/52/1/2 [r45]
I180110 18:03:00.114279 119285 storage/replica_command.go:819  [n1,s1,r36/1:/Table/51/1/0/#/52/1/{1-2}] initiating a split of this range at key /Table/51/1/0/#/52/1/1/#/53/1 [r46]
I180110 18:03:00.121526 119285 storage/replica_command.go:819  [n1,s1,r37/1:/Table/51/1/{0/#/52…-1}] initiating a split of this range at key /Table/51/1/0/#/52/1/2/#/53/1 [r47]
I180110 18:03:00.127570 119285 storage/replica_command.go:819  [n1,s1,r38/1:/Table/51/1/1/#/52/1/{1-2}] initiating a split of this range at key /Table/51/1/1/#/52/1/1/#/53/1 [r48]
I180110 18:03:00.131410 119285 storage/replica_command.go:819  [n1,s1,r39/1:/Table/51/1/{1/#/52…-2}] initiating a split of this range at key /Table/51/1/1/#/52/1/2/#/53/1 [r49]
I180110 18:03:00.134666 119285 storage/replica_command.go:819  [n1,s1,r40/1:/Table/51/1/2/#/52/1/{1-2}] initiating a split of this range at key /Table/51/1/2/#/52/1/1/#/53/1 [r50]
I180110 18:03:00.138930 119285 storage/replica_command.go:819  [n1,s1,r41/1:/Table/51/1/{2/#/52…-3}] initiating a split of this range at key /Table/51/1/2/#/52/1/2/#/53/1 [r51]
I180110 18:03:00.142102 119285 storage/replica_command.go:819  [n1,s1,r42/1:/Table/51/1/3/#/52/1/{1-2}] initiating a split of this range at key /Table/51/1/3/#/52/1/1/#/53/1 [r52]
I180110 18:03:00.146773 119285 storage/replica_command.go:819  [n1,s1,r43/1:/Table/51/1/{3/#/52…-4}] initiating a split of this range at key /Table/51/1/3/#/52/1/2/#/53/1 [r53]
I180110 18:03:00.153089 119285 storage/replica_command.go:819  [n1,s1,r44/1:/Table/51/1/4/#/52/1/{1-2}] initiating a split of this range at key /Table/51/1/4/#/52/1/1/#/53/1 [r54]
I180110 18:03:00.156921 119285 storage/replica_command.go:819  [n1,s1,r45/1:/Table/51/1/{4/#/52…-5}] initiating a split of this range at key /Table/51/1/4/#/52/1/2/#/53/1 [r55]
I180110 18:03:00.164474 119285 storage/replica_command.go:819  [n1,s1,r47/1:/Table/51/1/{0/#/52…-1}] initiating a split of this range at key /Table/51/1/0/#/54/1/1 [r56]
I180110 18:03:00.173135 119285 storage/replica_command.go:819  [n1,s1,r56/1:/Table/51/1/{0/#/54…-1}] initiating a split of this range at key /Table/51/1/0/#/54/1/2 [r57]
I180110 18:03:00.178226 119285 storage/replica_command.go:819  [n1,s1,r49/1:/Table/51/1/{1/#/52…-2}] initiating a split of this range at key /Table/51/1/1/#/54/1/1 [r58]
I180110 18:03:00.182743 119285 storage/replica_command.go:819  [n1,s1,r58/1:/Table/51/1/{1/#/54…-2}] initiating a split of this range at key /Table/51/1/1/#/54/1/2 [r59]
I180110 18:03:00.187677 119285 storage/replica_command.go:819  [n1,s1,r51/1:/Table/51/1/{2/#/52…-3}] initiating a split of this range at key /Table/51/1/2/#/54/1/1 [r60]
I180110 18:03:00.191390 119285 storage/replica_command.go:819  [n1,s1,r60/1:/Table/51/1/{2/#/54…-3}] initiating a split of this range at key /Table/51/1/2/#/54/1/2 [r61]
I180110 18:03:00.196240 119285 storage/replica_command.go:819  [n1,s1,r53/1:/Table/51/1/{3/#/52…-4}] initiating a split of this range at key /Table/51/1/3/#/54/1/1 [r62]
I180110 18:03:00.199671 119285 storage/replica_command.go:819  [n1,s1,r62/1:/Table/51/1/{3/#/54…-4}] initiating a split of this range at key /Table/51/1/3/#/54/1/2 [r63]
I180110 18:03:00.202414 119285 storage/replica_command.go:819  [n1,s1,r55/1:/Table/51/1/{4/#/52…-5}] initiating a split of this range at key /Table/51/1/4/#/54/1/1 [r64]
I180110 18:03:00.206213 119285 storage/replica_command.go:819  [n1,s1,r64/1:/Table/51/1/{4/#/54…-5}] initiating a split of this range at key /Table/51/1/4/#/54/1/2 [r65]
I180110 18:03:00.221491 119727 ccl/storageccl/export.go:124  [n1,s1,r47/1:/Table/51/1/0/#/5{2/1/…-4/1/1}] export [/Table/51/1/0/#/52/1/2/#/53/1,/Table/51/1/0/#/54/1/1)
I180110 18:03:00.221634 119726 ccl/storageccl/export.go:124  [n1,s1,r37/1:/Table/51/1/0/#/52/1/2{-/…}] export [/Table/51/1/0/#/52/1/2,/Table/51/1/0/#/52/1/2/#/53/1)
I180110 18:03:00.221726 119724 ccl/storageccl/export.go:124  [n1,s1,r36/1:/Table/51/1/0/#/52/1/1{-/…}] export [/Table/51/1/0/#/52/1/1,/Table/51/1/0/#/52/1/1/#/53/1)
I180110 18:03:00.221634 119723 ccl/storageccl/export.go:124  [n1,s1,r22/1:/Table/51{-/1/0/#/5…}] export [/Table/51/1,/Table/51/1/0/#/52/1/1)
I180110 18:03:00.221657 119725 ccl/storageccl/export.go:124  [n1,s1,r46/1:/Table/51/1/0/#/52/1/{1/…-2}] export [/Table/51/1/0/#/52/1/1/#/53/1,/Table/51/1/0/#/52/1/2)
I180110 18:03:00.224829 119762 ccl/storageccl/export.go:124  [n1,s1,r57/1:/Table/51/1/{0/#/54…-1}] export [/Table/51/1/0/#/54/1/2,/Table/51/1/1)
I180110 18:03:00.224909 119729 ccl/storageccl/export.go:124  [n1,s1,r56/1:/Table/51/1/0/#/54/1/{1-2}] export [/Table/51/1/0/#/54/1/1,/Table/51/1/0/#/54/1/2)
I180110 18:03:00.225032 119752 ccl/storageccl/export.go:124  [n1,s1,r38/1:/Table/51/1/1/#/52/1/1{-/…}] export [/Table/51/1/1/#/52/1/1,/Table/51/1/1/#/52/1/1/#/53/1)
I180110 18:03:00.225148 119751 ccl/storageccl/export.go:124  [n1,s1,r24/1:/Table/51/1/1{-/#/52/…}] export [/Table/51/1/1,/Table/51/1/1/#/52/1/1)
I180110 18:03:00.227625 119637 ccl/storageccl/export.go:124  [n1,s1,r48/1:/Table/51/1/1/#/52/1/{1/…-2}] export [/Table/51/1/1/#/52/1/1/#/53/1,/Table/51/1/1/#/52/1/2)
I180110 18:03:00.227662 119763 ccl/storageccl/export.go:124  [n1,s1,r39/1:/Table/51/1/1/#/52/1/2{-/…}] export [/Table/51/1/1/#/52/1/2,/Table/51/1/1/#/52/1/2/#/53/1)
I180110 18:03:00.227783 119695 ccl/storageccl/export.go:124  [n1,s1,r49/1:/Table/51/1/1/#/5{2/1/…-4/1/1}] export [/Table/51/1/1/#/52/1/2/#/53/1,/Table/51/1/1/#/54/1/1)
I180110 18:03:00.228066 119778 ccl/storageccl/export.go:124  [n1,s1,r59/1:/Table/51/1/{1/#/54…-2}] export [/Table/51/1/1/#/54/1/2,/Table/51/1/2)
I180110 18:03:00.227784 119753 ccl/storageccl/export.go:124  [n1,s1,r58/1:/Table/51/1/1/#/54/1/{1-2}] export [/Table/51/1/1/#/54/1/1,/Table/51/1/1/#/54/1/2)
I180110 18:03:00.231000 119639 ccl/storageccl/export.go:124  [n1,s1,r40/1:/Table/51/1/2/#/52/1/1{-/…}] export [/Table/51/1/2/#/52/1/1,/Table/51/1/2/#/52/1/1/#/53/1)
I180110 18:03:00.231028 119638 ccl/storageccl/export.go:124  [n1,s1,r25/1:/Table/51/1/2{-/#/52/…}] export [/Table/51/1/2,/Table/51/1/2/#/52/1/1)
I180110 18:03:00.231226 119764 ccl/storageccl/export.go:124  [n1,s1,r41/1:/Table/51/1/2/#/52/1/2{-/…}] export [/Table/51/1/2/#/52/1/2,/Table/51/1/2/#/52/1/2/#/53/1)
I180110 18:03:00.231284 119754 ccl/storageccl/export.go:124  [n1,s1,r50/1:/Table/51/1/2/#/52/1/{1/…-2}] export [/Table/51/1/2/#/52/1/1/#/53/1,/Table/51/1/2/#/52/1/2)
I180110 18:03:00.231284 119765 ccl/storageccl/export.go:124  [n1,s1,r51/1:/Table/51/1/2/#/5{2/1/…-4/1/1}] export [/Table/51/1/2/#/52/1/2/#/53/1,/Table/51/1/2/#/54/1/1)
I180110 18:03:00.234051 119608 ccl/storageccl/export.go:124  [n1,s1,r26/1:/Table/51/1/3{-/#/52/…}] export [/Table/51/1/3,/Table/51/1/3/#/52/1/1)
I180110 18:03:00.234057 119641 ccl/storageccl/export.go:124  [n1,s1,r61/1:/Table/51/1/{2/#/54…-3}] export [/Table/51/1/2/#/54/1/2,/Table/51/1/3)
I180110 18:03:00.234232 119640 ccl/storageccl/export.go:124  [n1,s1,r60/1:/Table/51/1/2/#/54/1/{1-2}] export [/Table/51/1/2/#/54/1/1,/Table/51/1/2/#/54/1/2)
I180110 18:03:00.234519 119564 ccl/storageccl/export.go:124  [n1,s1,r42/1:/Table/51/1/3/#/52/1/1{-/…}] export [/Table/51/1/3/#/52/1/1,/Table/51/1/3/#/52/1/1/#/53/1)
I180110 18:03:00.234570 119780 ccl/storageccl/export.go:124  [n1,s1,r52/1:/Table/51/1/3/#/52/1/{1/…-2}] export [/Table/51/1/3/#/52/1/1/#/53/1,/Table/51/1/3/#/52/1/2)
I180110 18:03:00.236747 119610 ccl/storageccl/export.go:124  [n1,s1,r53/1:/Table/51/1/3/#/5{2/1/…-4/1/1}] export [/Table/51/1/3/#/52/1/2/#/53/1,/Table/51/1/3/#/54/1/1)
I180110 18:03:00.236764 119609 ccl/storageccl/export.go:124  [n1,s1,r43/1:/Table/51/1/3/#/52/1/2{-/…}] export [/Table/51/1/3/#/52/1/2,/Table/51/1/3/#/52/1/2/#/53/1)
I180110 18:03:00.236833 119644 ccl/storageccl/export.go:124  [n1,s1,r27/1:/Table/51/1/4{-/#/52/…}] export [/Table/51/1/4,/Table/51/1/4/#/52/1/1)
I180110 18:03:00.236857 119643 ccl/storageccl/export.go:124  [n1,s1,r63/1:/Table/51/1/{3/#/54…-4}] export [/Table/51/1/3/#/54/1/2,/Table/51/1/4)
I180110 18:03:00.236842 119642 ccl/storageccl/export.go:124  [n1,s1,r62/1:/Table/51/1/3/#/54/1/{1-2}] export [/Table/51/1/3/#/54/1/1,/Table/51/1/3/#/54/1/2)
I180110 18:03:00.239370 119696 ccl/storageccl/export.go:124  [n1,s1,r54/1:/Table/51/1/4/#/52/1/{1/…-2}] export [/Table/51/1/4/#/52/1/1/#/53/1,/Table/51/1/4/#/52/1/2)
I180110 18:03:00.239471 119782 ccl/storageccl/export.go:124  [n1,s1,r64/1:/Table/51/1/4/#/54/1/{1-2}] export [/Table/51/1/4/#/54/1/1,/Table/51/1/4/#/54/1/2)
I180110 18:03:00.239371 119611 ccl/storageccl/export.go:124  [n1,s1,r44/1:/Table/51/1/4/#/52/1/1{-/…}] export [/Table/51/1/4/#/52/1/1,/Table/51/1/4/#/52/1/1/#/53/1)
I180110 18:03:00.239882 119645 ccl/storageccl/export.go:124  [n1,s1,r45/1:/Table/51/1/4/#/52/1/2{-/…}] export [/Table/51/1/4/#/52/1/2,/Table/51/1/4/#/52/1/2/#/53/1)
I180110 18:03:00.239915 119646 ccl/storageccl/export.go:124  [n1,s1,r55/1:/Table/51/1/4/#/5{2/1/…-4/1/1}] export [/Table/51/1/4/#/52/1/2/#/53/1,/Table/51/1/4/#/54/1/1)
I180110 18:03:00.242495 119794 ccl/storageccl/export.go:124  [n1,s1,r28/1:/Table/51/1/{5-6}] export [/Table/51/1/5,/Table/51/1/6)
I180110 18:03:00.242578 119567 ccl/storageccl/export.go:124  [n1,s1,r30/1:/Table/51/1/{7-8}] export [/Table/51/1/7,/Table/51/1/8)
I180110 18:03:00.242631 119783 ccl/storageccl/export.go:124  [n1,s1,r31/1:/Table/51/1/{8-9}] export [/Table/51/1/8,/Table/51/1/9)
I180110 18:03:00.242578 119648 ccl/storageccl/export.go:124  [n1,s1,r29/1:/Table/51/1/{6-7}] export [/Table/51/1/6,/Table/51/1/7)
I180110 18:03:00.242583 119697 ccl/storageccl/export.go:124  [n1,s1,r65/1:/Table/51/1/{4/#/54…-5}] export [/Table/51/1/4/#/54/1/2,/Table/51/1/5)
I180110 18:03:00.245395 119568 ccl/storageccl/export.go:124  [n1,s1,r32/1:/Table/5{1/1/9-2}] export [/Table/51/1/9,/Table/51/2)
--- FAIL: test/TestBackupRestoreInterleaved/all_tables_in_interleave_hierarchy (0.000s)
Test ended in panic.

------- Stdout: -------
W180110 18:03:00.275286 119831 server/status/runtime.go:109  Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006"
I180110 18:03:00.281610 119831 server/config.go:518  [n?] 1 storage engine initialized
I180110 18:03:00.281656 119831 server/config.go:521  [n?] RocksDB cache size: 128 MiB
I180110 18:03:00.281667 119831 server/config.go:521  [n?] store 0: in-memory, size 0 B
I180110 18:03:00.285388 119831 server/node.go:361  [n?] **** cluster e5fa619e-84b4-4546-b83e-035c0afbcb10 has been created
I180110 18:03:00.285454 119831 server/server.go:934  [n?] **** add additional nodes by specifying --join=127.0.0.1:35605
I180110 18:03:00.286184 119831 storage/store.go:1312  [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available
I180110 18:03:00.286249 119831 server/node.go:491  [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=3.2 KiB), ranges=1, leases=0, writes=0.00, bytesPerReplica={p10=3322.00 p25=3322.00 p50=3322.00 p75=3322.00 p90=3322.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00}
I180110 18:03:00.286281 119831 server/node.go:339  [n1] node ID 1 initialized
I180110 18:03:00.286323 119831 gossip/gossip.go:332  [n1] NodeDescriptor set to node_id:1 address:<network_field:"tcp" address_field:"127.0.0.1:35605" > attrs:<> locality:<> ServerVersion:<major_val:1 minor_val:1 patch:0 unstable:9 > 
I180110 18:03:00.286446 119831 storage/stores.go:331  [n1] read 0 node addresses from persistent storage
I180110 18:03:00.286553 119831 server/node.go:632  [n1] connecting to gossip network to verify cluster ID...
I180110 18:03:00.286585 119831 server/node.go:657  [n1] node connected via gossip and verified as part of cluster "e5fa619e-84b4-4546-b83e-035c0afbcb10"
I180110 18:03:00.286610 119831 server/node.go:433  [n1] node=1: started with [<no-attributes>=<in-mem>] engine(s) and attributes []
I180110 18:03:00.286667 119831 sql/distsql_physical_planner.go:122  [n1] creating DistSQLPlanner with address {tcp 127.0.0.1:35605}
I180110 18:03:00.287975 119768 storage/replica_command.go:819  [split,n1,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2]
I180110 18:03:00.290150 119831 server/server.go:1161  [n1] starting https server at 127.0.0.1:46291
I180110 18:03:00.290180 119831 server/server.go:1162  [n1] starting grpc/postgres server at 127.0.0.1:35605
I180110 18:03:00.290190 119831 server/server.go:1163  [n1] advertising CockroachDB node at 127.0.0.1:35605
I180110 18:03:00.303117 119768 storage/replica_command.go:819  [split,n1,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3]
I180110 18:03:00.309002 119768 storage/replica_command.go:819  [split,n1,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4]
W180110 18:03:00.310214 120037 storage/intent_resolver.go:324  [n1,s1] failed to push during intent resolution: failed to push "sql txn implicit" id=dca6c167 key=/Table/SystemConfigSpan/Start rw=true pri=0.03337446 iso=SERIALIZABLE stat=PENDING epo=0 ts=1515607380.304345637,0 orig=1515607380.304345637,0 max=1515607380.304345637,0 wto=false rop=false seq=7
I180110 18:03:00.310846 119831 sql/event_log.go:115  [n1] Event: "alter_table", target: 12, info: {TableName:eventlog Statement:ALTER TABLE system.eventlog ALTER COLUMN "uniqueID" SET DEFAULT uuid_v4() User:node MutationID:0 CascadeDroppedViews:[]}
W180110 18:03:00.313544 120067 storage/intent_resolver.go:324  [n1,s1] failed to push during intent resolution: failed to push "split" id=56ea7810 key=/Local/Range/System/NodeLiveness/RangeDescriptor rw=true pri=0.00888184 iso=SERIALIZABLE stat=PENDING epo=0 ts=1515607380.309028972,0 orig=1515607380.309028972,0 max=1515607380.309028972,0 wto=false rop=false seq=3
I180110 18:03:00.314936 119768 storage/replica_command.go:819  [split,n1,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5]
I180110 18:03:00.315957 119831 sql/lease.go:348  [n1] publish: descID=12 (eventlog) version=2 mtime=2018-01-10 18:03:00.315829678 +0000 UTC
I180110 18:03:00.319063 119768 storage/replica_command.go:819  [split,n1,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6]
I180110 18:03:00.325466 119768 storage/replica_command.go:819  [split,n1,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7]
I180110 18:03:00.328366 119831 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:node}
I180110 18:03:00.329842 119768 storage/replica_command.go:819  [split,n1,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8]
I180110 18:03:00.335208 119768 storage/replica_command.go:819  [split,n1,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9]
I180110 18:03:00.339886 119831 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:$1 User:node}
I180110 18:03:00.340273 119768 storage/replica_command.go:819  [split,n1,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10]
I180110 18:03:00.343763 119768 storage/replica_command.go:819  [split,n1,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11]
I180110 18:03:00.345078 119831 sql/event_log.go:115  [n1] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:node}
I180110 18:03:00.348228 119768 storage/replica_command.go:819  [split,n1,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12]
I180110 18:03:00.351319 119768 storage/replica_command.go:819  [split,n1,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13]
I180110 18:03:00.357426 119768 storage/replica_command.go:819  [split,n1,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14]
I180110 18:03:00.359871 119831 sql/event_log.go:115  [n1] Event: "alter_table", target: 4, info: {TableName:users Statement:ALTER TABLE system.users ADD COLUMN IF NOT EXISTS "isRole" BOOL NOT NULL DEFAULT false User:node MutationID:1 CascadeDroppedViews:[]}
I180110 18:03:00.361795 119768 storage/replica_command.go:819  [split,n1,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15]
I180110 18:03:00.362485 119831 sql/lease.go:348  [n1] publish: descID=4 (users) version=2 mtime=2018-01-10 18:03:00.362378 +0000 UTC
I180110 18:03:00.365402 119768 storage/replica_command.go:819  [split,n1,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16]
I180110 18:03:00.367126 119831 sql/lease.go:348  [n1] publish: descID=4 (users) version=3 mtime=2018-01-10 18:03:00.366998973 +0000 UTC
I180110 18:03:00.369005 119768 storage/replica_command.go:819  [split,n1,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17]
I180110 18:03:00.371107 119831 sql/backfill.go:133  [n1] Running backfill for "users", v=3, m=1
I180110 18:03:00.372228 119768 storage/replica_command.go:819  [split,n1,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18]
I180110 18:03:00.375920 119768 storage/replica_command.go:819  [split,n1,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19]
I180110 18:03:00.380211 119768 storage/replica_command.go:819  [split,n1,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20]
I180110 18:03:00.380849 119831 sql/lease.go:348  [n1] publish: descID=4 (users) version=4 mtime=2018-01-10 18:03:00.380596668 +0000 UTC
I180110 18:03:00.385248 119831 sql/event_log.go:115  [n1] Event: "finish_schema_change", target: 4, info: {MutationID:1}
I180110 18:03:00.386245 119831 sql/lease.go:274  publish (count leases): descID=4 name=users version=3 count=1
I180110 18:03:00.418753 119831 server/server.go:1232  [n1] done ensuring all necessary migrations have run
I180110 18:03:00.418794 119831 server/server.go:1235  [n1] serving sql connections
I180110 18:03:00.421106 120299 sql/event_log.go:115  [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:35605} Attrs: Locality: ServerVersion:1.1-9} ClusterID:e5fa619e-84b4-4546-b83e-035c0afbcb10 StartedAt:1515607380286590075 LastUp:1515607380286590075}
I180110 18:03:00.433218 120174 sql/event_log.go:115  [client=127.0.0.1:50924,user=root,n1] Event: "create_database", target: 50, info: {DatabaseName:ignored Statement:CREATE DATABASE ignored User:root}
I180110 18:03:00.433578 119768 storage/replica_command.go:819  [split,n1,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21]
I180110 18:03:00.435962 120174 sql/event_log.go:115  [client=127.0.0.1:50924,user=root,n1] Event: "create_database", target: 51, info: {DatabaseName:data Statement:CREATE DATABASE data User:root}
I180110 18:03:00.439496 119768 storage/replica_command.go:819  [split,n1,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22]
I180110 18:03:00.445885 120339 storage/replica_command.go:819  [n1,s1,r22/1:/{Table/51-Max}] initiating a split of this range at key /Table/52 [r23]
I180110 18:03:00.453388 120339 storage/replica_command.go:819  [n1,s1,r23/1:/{Table/52-Max}] initiating a split of this range at key /Table/52/1/0/#/55/1/2 [r24]
I180110 18:03:00.454107 120341 storage/replica_command.go:819  [n1,s1,r23/1:/{Table/52-Max}] initiating a split of this range at key /Table/52/1/0/#/53/1/1 [r25]
I180110 18:03:00.462172 120339 storage/replica_command.go:819  [n1,s1,r24/1:/{Table/52/1/0…-Max}] initiating a split of this range at key /Table/52/1/1/#/55/1/1 [r26]
I180110 18:03:00.463059 120340 storage/replica_command.go:819  [n1,s1,r24/1:/{Table/52/1/0…-Max}] initiating a split of this range at key /Table/52/1/1 [r27]
W180110 18:03:00.468477 120310 storage/replica.go:2174  [n1,s1,r24/1:/Table/52/1/{0/#/55…-1/#/55…}] context canceled before command queue: 1 QueryTxn
I180110 18:03:00.511020 120341 storage/replica_command.go:819  [n1,s1,r23/1:/Table/52{-/1/0/#/5…}] initiating a split of this range at key /Table/52/1/0/#/53/1/1 [r28]
I180110 18:03:00.515293 120340 storage/replica_command.go:819  [n1,s1,r24/1:/Table/52/1/{0/#/55…-1/#/55…}] initiating a split of this range at key /Table/52/1/1 [r29]
I180110 18:03:00.517083 120341 storage/replica_command.go:819  [n1,s1,r28/1:/Table/52/1/0/#/5{3/1/1-5/1/2}] initiating a split of this range at key /Table/52/1/0/#/53/1/1/#/54/1 [r30]
I180110 18:03:00.521277 120340 storage/replica_command.go:819  [n1,s1,r29/1:/Table/52/1/1{-/#/55/…}] initiating a split of this range at key /Table/52/1/1/#/53/1/1 [r31]
I180110 18:03:00.522960 120341 storage/replica_command.go:819  [n1,s1,r30/1:/Table/52/1/0/#/5{3/1/…-5/1/2}] initiating a split of this range at key /Table/52/1/0/#/53/1/2 [r32]
I180110 18:03:00.526073 120341 storage/replica_command.go:819  [n1,s1,r32/1:/Table/52/1/0/#/5{3/1/2-5/1/2}] initiating a split of this range at key /Table/52/1/0/#/53/1/2/#/54/1 [r33]
I180110 18:03:00.527339 120340 storage/replica_command.go:819  [n1,s1,r31/1:/Table/52/1/1/#/5{3/1/1-5/1/1}] initiating a split of this range at key /Table/52/1/1/#/53/1/1/#/54/1 [r34]
I180110 18:03:00.530427 120340 storage/replica_command.go:819  [n1,s1,r34/1:/Table/52/1/1/#/5{3/1/…-5/1/1}] initiating a split of this range at key /Table/52/1/1/#/53/1/2 [r35]
I180110 18:03:00.531312 120341 storage/replica_command.go:819  [n1,s1,r33/1:/Table/52/1/0/#/5{3/1/…-5/1/2}] initiating a split of this range at key /Table/52/1/0/#/55/1/1 [r36]
I180110 18:03:00.534390 120340 storage/replica_command.go:819  [n1,s1,r35/1:/Table/52/1/1/#/5{3/1/2-5/1/1}] initiating a split of this range at key /Table/52/1/1/#/53/1/2/#/54/1 [r37]
I180110 18:03:00.536031 120341 storage/replica_command.go:819  [n1,s1,r26/1:/{Table/52/1/1…-Max}] initiating a split of this range at key /Table/52/1/1/#/55/1/2 [r38]
I180110 18:03:00.536192 120339 storage/replica_command.go:819  [n1,s1,r26/1:/{Table/52/1/1…-Max}] initiating a split of this range at key /Table/52/1/2/#/53/1/2/#/54/1 [r39]
W180110 18:03:00.539966 120490 storage/replica.go:2174  [n1,s1,r26/1:/Table/52/1/1/#/55/1/{1-2}] context canceled before command queue: 1 QueryTxn
I180110 18:03:00.540236 120341 storage/replica_command.go:819  [n1,s1,r38/1:/{Table/52/1/1…-Max}] initiating a split of this range at key /Table/52/1/2 [r40]
I180110 18:03:00.545769 120341 storage/replica_command.go:819  [n1,s1,r40/1:/{Table/52/1/2-Max}] initiating a split of this range at key /Table/52/1/2/#/53/1/1 [r41]
I180110 18:03:00.550971 120341 storage/replica_command.go:819  [n1,s1,r41/1:/{Table/52/1/2…-Max}] initiating a split of this range at key /Table/52/1/2/#/53/1/1/#/54/1 [r42]
I180110 18:03:00.558917 120341 storage/replica_command.go:819  [n1,s1,r42/1:/{Table/52/1/2…-Max}] initiating a split of this range at key /Table/52/1/2/#/53/1/2 [r43]
I180110 18:03:00.594970 120339 storage/replica_command.go:819  [n1,s1,r43/1:/{Table/52/1/2…-Max}] initiating a split of this range at key /Table/52/1/2/#/53/1/2/#/54/1 [r44]
I180110 18:03:00.599792 120339 storage/replica_command.go:819  [n1,s1,r44/1:/{Table/52/1/2…-Max}] initiating a split of this range at key /Table/52/1/3/#/53/1/2 [r45]
I180110 18:03:00.600503 120340 storage/replica_command.go:819  [n1,s1,r44/1:/{Table/52/1/2…-Max}] initiating a split of this range at key /Table/52/1/2/#/55/1/1 [r46]
W180110 18:03:00.607605 120619 storage/replica.go:2174  [n1,s1,r44/1:/Table/52/1/{2/#/53…-3/#/53…}] context canceled before command queue: 1 QueryTxn
I180110 18:03:00.607847 120339 storage/replica_command.go:819  [n1,s1,r45/1:/{Table/52/1/3…-Max}] initiating a split of this range at key /Table/52/1/4/#/53/1/1/#/54/1 [r47]
I180110 18:03:00.608619 120341 storage/replica_command.go:819  [n1,s1,r45/1:/{Table/52/1/3…-Max}] initiating a split of this range at key /Table/52/1/3/#/53/1/2/#/54/1 [r48]
W180110 18:03:00.614903 120572 storage/replica.go:2174  [n1,s1,r45/1:/Table/52/1/{3/#/53…-4/#/53…}] context canceled before command queue: 1 QueryTxn
I180110 18:03:00.654583 120340 storage/replica_command.go:819  [n1,s1,r44/1:/Table/52/1/{2/#/53…-3/#/53…}] initiating a split of this range at key /Table/52/1/2/#/55/1/1 [r49]
I180110 18:03:00.660522 120340 storage/replica_command.go:819  [n1,s1,r49/1:/Table/52/1/{2/#/55…-3/#/53…}] initiating a split of this range at key /Table/52/1/2/#/55/1/2 [r50]
I180110 18:03:00.664488 120341 storage/replica_command.go:819  [n1,s1,r45/1:/Table/52/1/{3/#/53…-4/#/53…}] initiating a split of this range at key /Table/52/1/3/#/53/1/2/#/54/1 [r51]
I180110 18:03:00.667950 120340 storage/replica_command.go:819  [n1,s1,r50/1:/Table/52/1/{2/#/55…-3/#/53…}] initiating a split of this range at key /Table/52/1/3 [r52]
I180110 18:03:00.669715 120341 storage/replica_command.go:819  [n1,s1,r51/1:/Table/52/1/{3/#/53…-4/#/53…}] initiating a split of this range at key /Table/52/1/3/#/55/1/1 [r53]
I180110 18:03:00.673659 120340 storage/replica_command.go:819  [n1,s1,r52/1:/Table/52/1/3{-/#/53/…}] initiating a split of this range at key /Table/52/1/3/#/53/1/1 [r54]
I180110 18:03:00.673762 120341 storage/replica_command.go:819  [n1,s1,r53/1:/Table/52/1/{3/#/55…-4/#/53…}] initiating a split of this range at key /Table/52/1/3/#/55/1/2 [r55]
I180110 18:03:00.677249 120340 storage/replica_command.go:819  [n1,s1,r54/1:/Table/52/1/3/#/53/1/{1-2}] initiating a split of this range at key /Table/52/1/3/#/53/1/1/#/54/1 [r56]
I180110 18:03:00.677963 120341 storage/replica_command.go:819  [n1,s1,r55/1:/Table/52/1/{3/#/55…-4/#/53…}] initiating a split of this range at key /Table/52/1/4 [r57]
I180110 18:03:00.682706 120339 storage/replica_command.go:819  [n1,s1,r47/1:/{Table/52/1/4…-Max}] initiating a split of this range at key /Table/52/1/6 [r58]
I180110 18:03:00.683136 120341 storage/replica_command.go:819  [n1,s1,r57/1:/Table/52/1/4{-/#/53/…}] initiating a split of this range at key /Table/52/1/4/#/53/1/1 [r59]
I180110 18:03:00.683623 120340 storage/replica_command.go:819  [n1,s1,r47/1:/{Table/52/1/4…-Max}] initiating a split of this range at key /Table/52/1/4/#/53/1/2 [r60]
W180110 18:03:00.686715 120739 storage/replica.go:2174  [n1,s1,r47/1:/Table/52/1/{4/#/53…-6}] context canceled before command queue: 1 QueryTxn
I180110 18:03:00.687267 120341 storage/replica_command.go:819  [n1,s1,r58/1:/{Table/52/1/6-Max}] initiating a split of this range at key /Table/52/1/7 [r61]
I180110 18:03:00.692013 120341 storage/replica_command.go:819  [n1,s1,r61/1:/{Table/52/1/7-Max}] initiating a split of this range at key /Table/52/1/8 [r62]
I180110 18:03:00.700994 120341 storage/replica_command.go:819  [n1,s1,r62/1:/{Table/52/1/8-Max}] initiating a split of this range at key /Table/52/1/9 [r63]
panic: test timed out after 4m0s

goroutine 120721 [running]:
testing.startAlarm.func1()
	/usr/local/go/src/testing/testing.go:1145 +0xf9
created by time.goFunc
	/usr/local/go/src/time/sleep.go:170 +0x44

goroutine 1 [chan receive]:
testing.(*T).Run(0xc4200c2690, 0x233f0da, 0x1c, 0x23ff290, 0x8d4f01)
	/usr/local/go/src/testing/testing.go:790 +0x2fc
testing.runTests.func1(0xc4200c2690)
	/usr/local/go/src/testing/testing.go:1004 +0x64
testing.tRunner(0xc4200c2690, 0xc42067bdb8)
	/usr/local/go/src/testing/testing.go:746 +0xd0
testing.runTests(0xc4201ddc00, 0x3410660, 0x38, 0x38, 0x0)
	/usr/local/go/src/testing/testing.go:1002 +0x2d8
testing.(*M).Run(0xc420a27f18, 0xc420086500)
	/usr/local/go/src/testing/testing.go:921 +0x111
github.com/cockroachdb/cockroach/pkg/ccl/sqlccl.TestMain(0xc42067bf18)
	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/sqlccl/main_test.go:31 +0xda
main.main()
	github.com/cockroachdb/cockroach/pkg/ccl/sqlccl/_test/_testmain.go:172 +0xdb

goroutine 24 [chan receive]:
github.com/cockroachdb/cockroach/pkg/util/log.(*loggingT).flushDaemon(0x365efa0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:1043 +0x81
created by github.com/cockroachdb/cockroach/pkg/util/log.init.0
	/go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:581 +0xbf

goroutine 50 [syscall, 4 minutes]:
os/signal.signal_recv(0x0)
	/usr/local/go/src/runtime/sigqueue.go:131 +0xa6
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:28 +0x41

goroutine 118774 [chan receive]:
testing.(*T).Run(0xc4215f64b0, 0x234c57a, 0x22, 0xc4202f3080, 0x1a)
	/usr/local/go/src/testing/testing.go:790 +0x2fc
github.com/cockroachdb/cockroach/pkg/ccl/sqlccl_test.TestBackupRestoreInterleaved(0xc4215f64b0)
	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/sqlccl/backup_test.go:1065 +0x937
testing.tRunner(0xc4215f64b0, 0x23ff290)
	/usr/local/go/src/testing/testing.go:746 +0xd0
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:789 +0x2de

goroutine 5 [select, locked to thread]:
runtime.gopark(0x2403108, 0x0, 0x2319caf, 0x6, 0x18, 0x1)
	/usr/local/go/src/runtime/proc.go:277 +0x12c
runtime.selectgo(0xc420041f50, 0xc42048ed80)
	/usr/local/go/src/runtime/select.go:395 +0x1138
runtime.ensureSigM.func1()
	/usr/local/go/src/runtime/signal_unix.go:511 +0x220
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:2337 +0x1

goroutine 118948 [semacquire]:
sync.runtime_notifyListWait(0xc423412890, 0xc4000003ae)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc423412880)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc420b5d440, 0x343ba20, 0xc423a6ecf0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc423a6ecf0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420344f10, 0xc4210b58c0, 0xc420344ee0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 120716 [semacquire]:
sync.runtime_Semacquire(0xc42008f6d4)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc42008f6c8)
	/usr/local/go/src/sync/waitgroup.go:131 +0x72
github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup.(*Group).Wait(0xc42008f6c0, 0xc4216028a0, 0x2345377)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup/errgroup.go:41 +0x31
github.com/cockroachdb/cockroach/pkg/ccl/storageccl.evalImport(0x343ba20, 0xc4216028a0, 0x344ec60, 0xc423526000, 0x150884e1f9f193d6, 0x0, 0x100000001, 0x1, 0x3f, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/storageccl/import.go:311 +0x2084
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).executeAdminBatch(0xc423526000, 0x343ba20, 0xc4216028a0, 0x150884e1f9f193d6, 0x0, 0x100000001, 0x1, 0x3f, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:2485 +0xacd
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).Send(0xc423526000, 0x343ba20, 0xc4216028a0, 0x150884e1f9f193d6, 0x0, 0x100000001, 0x1, 0x3f, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica.go:1919 +0x60f
github.com/cockroachdb/cockroach/pkg/storage.(*Store).Send(0xc42354c400, 0x343ba20, 0xc421602870, 0x150884e1f9f193d6, 0x0, 0x100000001, 0x1, 0x3f, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:2688 +0x688
github.com/cockroachdb/cockroach/pkg/storage.(*Stores).Send(0xc423198bb0, 0x343ba20, 0xc421602810, 0x0, 0x0, 0x100000001, 0x1, 0x3f, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/stores.go:214 +0x214
github.com/cockroachdb/cockroach/pkg/server.(*Node).batchInternal.func1(0x343ba20, 0xc421602810, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/server/node.go:865 +0x192
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunTaskWithErr(0xc4253dbb00, 0x343ba20, 0xc421602810, 0x232938b, 0x10, 0xc422157cf8, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:245 +0xf7
github.com/cockroachdb/cockroach/pkg/server.(*Node).batchInternal(0xc424f8d200, 0x343ba20, 0xc421602810, 0xc423e212a8, 0xc421602810, 0x14ecafe, 0x343ba20)
	/go/src/github.com/cockroachdb/cockroach/pkg/server/node.go:852 +0x152
github.com/cockroachdb/cockroach/pkg/server.(*Node).Batch(0xc424f8d200, 0x343ba20, 0xc421602810, 0xc423e212a8, 0x1f, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/server/node.go:893 +0x99
github.com/cockroachdb/cockroach/pkg/kv.(*grpcTransport).send.func1(0xc4218db490, 0xc423e21290, 0x343ba20, 0xc421602750, 0x100000000, 0xc42256e1d8, 0x8580c8)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/transport.go:243 +0x6b0
github.com/cockroachdb/cockroach/pkg/kv.(*grpcTransport).send(0xc4218db490, 0x343ba20, 0xc421602750, 0xc421fd9ce0, 0xf, 0xc42275ce60, 0x0, 0x0, 0x100000001, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/transport.go:271 +0x9a
github.com/cockroachdb/cockroach/pkg/kv.(*grpcTransport).SendNext(0xc4218db490, 0x343ba20, 0xc421602750, 0xc4234e5b60)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/transport.go:208 +0x31b
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendToReplicas(0xc42474d1d0, 0x343ba20, 0xc421602750, 0xc42474d220, 0x3f, 0xc42356b3c0, 0x1, 0x1, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:1246 +0x3a4
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendRPC(0xc42474d1d0, 0x343ba20, 0xc421602750, 0x3f, 0xc42356b3c0, 0x1, 0x1, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:382 +0x27b
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendSingleRange(0xc42474d1d0, 0x343ba20, 0xc421602750, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:446 +0x16e
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).sendPartialBatch(0xc42474d1d0, 0x343ba20, 0xc421602750, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:1024 +0x347
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).divideAndSendBatchToRanges(0xc42474d1d0, 0x343ba20, 0xc421602750, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:700 +0x16f8
github.com/cockroachdb/cockroach/pkg/kv.(*DistSender).Send(0xc42474d1d0, 0x343ba20, 0xc421602750, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/dist_sender.go:621 +0x3f5
github.com/cockroachdb/cockroach/pkg/kv.(*TxnCoordSender).Send(0xc4228b22a0, 0x343ba20, 0xc421602750, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/txn_coord_sender.go:444 +0x1ce
github.com/cockroachdb/cockroach/pkg/internal/client.SendWrappedWith(0x343b960, 0xc420878840, 0x341b060, 0xc4228b22a0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/sender.go:62 +0x143
github.com/cockroachdb/cockroach/pkg/internal/client.SendWrapped(0x343b960, 0xc420878840, 0x341b060, 0xc4228b22a0, 0x34496e0, 0xc4253e6be0, 0xc422397880, 0xc424252f78, 0x16d2656)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/sender.go:79 +0xaf
github.com/cockroachdb/cockroach/pkg/ccl/sqlccl.restore.func4(0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/sqlccl/restore.go:967 +0x13e
github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup.(*Group).Go.func1(0xc420878880, 0xc4234e5b00)
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup/errgroup.go:58 +0x57
created by github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup.(*Group).Go
	/go/src/github.com/cockroachdb/cockroach/vendor/golang.org/x/sync/errgroup/errgroup.go:55 +0x66

goroutine 118949 [semacquire]:
sync.runtime_notifyListWait(0xc423412890, 0xc4000003a9)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc423412880)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc420b5d440, 0x343ba20, 0xc425475e90)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc425475e90)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420344f40, 0xc4210b58c0, 0xc420344f20)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 119790 [select]:
github.com/cockroachdb/cockroach/pkg/server.(*Server).startSampleEnvironment.func1(0x343ba20, 0xc420846120)
	/go/src/github.com/cockroachdb/cockroach/pkg/server/server.go:1416 +0x16c
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc424060280, 0xc4253dbb00, 0xc4201dde00)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118988 [select]:
github.com/cockroachdb/cockroach/pkg/sql.(*DistSQLPlanner).initRunners.func1(0x343ba20, 0xc421227050)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/distsql_running.go:86 +0x167
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4204538d0, 0xc4210b58c0, 0xc4204538c0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118965 [semacquire]:
sync.runtime_Semacquire(0xc420b5d4c4)
	/usr/local/go/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc420b5d4b8)
	/usr/local/go/src/sync/waitgroup.go:131 +0x72
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Wait(0xc420b5d440, 0x343ba20, 0xc425475fb0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:172 +0x31
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Wait-fm(0x343ba20, 0xc425475fb0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:3834 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420345270, 0xc4210b58c0, 0xc420345260)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118820 [chan receive]:
github.com/cockroachdb/cockroach/pkg/gossip.(*server).start.func3(0x343ba20, 0xc42303c3f0)
	/go/src/github.com/cockroachdb/cockroach/pkg/gossip/server.go:371 +0x5a
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203763e0, 0xc4210b58c0, 0xc422f01b00)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118818 [chan receive]:
github.com/cockroachdb/cockroach/vendor/github.com/cockroachdb/cmux.muxListener.Accept(...)
	/go/src/github.com/cockroachdb/cockroach/vendor/github.com/cockroachdb/cmux/cmux.go:184
github.com/cockroachdb/cockroach/vendor/github.com/cockroachdb/cmux.(*muxListener).Accept(0xc422f016a0, 0x24024e8, 0xc4207cba40, 0x34478c0, 0xc422a1b220)
	<autogenerated>:1 +0x65
github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*Server).Serve(0xc4207cba40, 0x343aba0, 0xc422f016a0, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/server.go:463 +0x196
github.com/cockroachdb/cockroach/pkg/server.(*Server).Start.func7(0x343ba20, 0xc42303c3c0)
	/go/src/github.com/cockroachdb/cockroach/pkg/server/server.go:795 +0x43
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4203761c0, 0xc4210b58c0, 0xc422f01980)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 119938 [semacquire]:
sync.runtime_notifyListWait(0xc4208d8310, 0xc400000325)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc4208d8300)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc4226ac7e0, 0x343ba20, 0xc420afda10)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc420afda10)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420452b80, 0xc4253dbb00, 0xc420452b70)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 119973 [semacquire]:
sync.runtime_notifyListWait(0xc4208d8310, 0xc40000033c)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc4208d8300)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc4226ac7e0, 0x343ba20, 0xc420d947e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc420d947e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc4204531f0, 0xc4253dbb00, 0xc4204531e0)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118906 [semacquire]:
sync.runtime_notifyListWait(0xc423412890, 0xc4000003b5)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc423412880)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc420b5d440, 0x343ba20, 0xc42303c870)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc42303c870)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420344680, 0xc4210b58c0, 0xc420344670)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118911 [semacquire]:
sync.runtime_notifyListWait(0xc423412890, 0xc4000003b8)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc423412880)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc420b5d440, 0x343ba20, 0xc423a6eab0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:197 +0x7c
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).Start.func2(0x343ba20, 0xc423a6eab0)
	/go/src/github.com/cockroachdb/cockroach/pkg/storage/scheduler.go:166 +0x3e
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc420344770, 0xc4210b58c0, 0xc420344760)
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0xf3
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
	/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xad

goroutine 118928 [semacquire]:
sync.runtime_notifyListWait(0xc423412890, 0xc4000003c2)
	/usr/local/go/src/runtime/sema.go:507 +0x110
sync.(*Cond).Wait(0xc423412880)
	/usr/local/go/src/sync/cond.go:56 +0x80
github.com/cockroachdb/cockroach/pkg/storage.(*raftScheduler).worker(0xc420b5d440, 0x343ba20, 0xc42303cb70)
	/go/src/github.com/co

Please assign, take a look and update the issue accordingly.
@cockroach-teamcity cockroach-teamcity added O-robot Originated from a bot. C-test-failure Broken test (automatically or manually discovered). labels Jan 10, 2018
@benesch
Copy link
Contributor

benesch commented Jan 20, 2018

Time out caused by slow partitioning tests. Fixed by #21392.

@benesch benesch closed this as completed Jan 20, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@benesch @cockroach-teamcity