teamcity: failed test: TestRepartitioning #38427
Description
The following tests appear to have failed on master (testrace): TestRepartitioning/multi_col_list_partitioning_-DEFAULT_DEFAULT/multi_col_list_partitioning-DEFAULT, TestRepartitioning/single_col_list_partitioning-DEFAULT/single_col_list_partitioning, TestRepartitioning/unpartitioned/unpartitioned, TestRepartitioning/single_col_range_partitioning-MAXVALUE/single_col_range_partitioning, TestRepartitioning/multi_col_range_partitioning/multi_col_range_partitioning-MAXVALUE, TestRepartitioning/multi_col_range_partitioning-MAXVALUE/multi_col_range_partitioning, TestRepartitioning/multi_col_list_partitioning-DEFAULT/multi_col_list_partitioning, TestRepartitioning/single_col_list_partitioning/single_col_list_partitioning-DEFAULT, TestRepartitioning/multi_col_range_partitioning-MAXVALUE_MAXVALUE/multi_col_range_partitioning-MAXVALUE, TestRepartitioning, TestRepartitioning/multi_col_range_partitioning-MAXVALUE/multi_col_range_partitioning-MAXVALUE_MAXVALUE, TestRepartitioning/unpartitioned/single_col_list_partitioning, TestRepartitioning/single_col_range_partitioning/single_col_range_partitioning-MAXVALUE, TestRepartitioning/unpartitioned/single_col_range_partitioning-MAXVALUE, TestRepartitioning/unpartitioned/single_col_list_partitioning-DEFAULT, TestRepartitioning/multi_col_list_partitioning-DEFAULT/multi_col_list_partitioning-DEFAULT_DEFAULT, TestRepartitioning/multi_col_list_partitioning/multi_col_list_partitioning-_DEFAULT, TestRepartitioning/unpartitioned/single_col_range_partitioning
You may want to check for open issues.
TestRepartitioning/multi_col_list_partitioning/multi_col_list_partitioning_-_DEFAULT
...6 00:54:18.335466 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) < (3, 4)
I190626 00:54:18.389712 619370 storage/store_snapshot.go:774 [n1,raftsnapshot,s1,r38/1:/Table/68/1/5{-/7}] sending RAFT snapshot 50ca6663 at applied index 14
I190626 00:54:18.393142 619370 storage/store_snapshot.go:817 [n1,raftsnapshot,s1,r38/1:/Table/68/1/5{-/7}] streamed snapshot to (n2,s2):2: kv pairs: 16, log entries: 0, rate-limit: 8.0 MiB/sec, 0.01s
I190626 00:54:18.403253 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 3 AND b = 4
I190626 00:54:18.408737 619341 storage/replica_raftstorage.go:808 [n2,s2,r38/2:{-}] applying RAFT snapshot at index 14 (id=50ca6663, encoded size=1162, 1 rocksdb batches, 0 log entries)
I190626 00:54:18.433871 619341 storage/replica_raftstorage.go:814 [n2,s2,r38/2:/Table/68/1/5{-/7}] applied RAFT snapshot in 25ms [clear=18ms batch=0ms entries=0ms commit=0ms]
I190626 00:54:18.503381 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) > (3, 4) AND a < 5
I190626 00:54:18.557861 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:54:18.614999 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 7
E190626 00:54:18.701008 619873 storage/queue.go:1033 [n1,replicate,s1,r33/3:/Table/{58/2-60}] no removable replicas from range that needs a removal: [3*:42, 5:0]
I190626 00:54:18.761626 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 7
I190626 00:54:18.804433 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 8
I190626 00:54:18.839020 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b > 8
E190626 00:54:18.864885 620315 storage/queue.go:1033 [n2,replicate,s2,r38/2:/Table/68/1/5{-/7}] no removable replicas from range that needs a removal: [1:0, 2*:17]
I190626 00:54:18.907693 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a > 5
I190626 00:54:18.947296 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) < (3, 4)
I190626 00:54:18.996061 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 3 AND b = 4
E190626 00:54:19.085342 620750 storage/queue.go:1033 [n1,replicate,s1,r33/3:/Table/{58/2-60}] no removable replicas from range that needs a removal: [3*:42, 5:0]
I190626 00:54:19.105369 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) > (3, 4) AND a < 5
I190626 00:54:19.141463 589572 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:54:19.155891 620800 storage/replica_command.go:933 [n2,replicate,s2,r38/2:/Table/68/1/5{-/7}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r38:/Table/68/1/5{-/7} [(n1,s1):1, (n2,s2):2, next=3, gen=39]
I190626 00:54:19.302375 620800 storage/replica_raft.go:395 [n2,s2,r38/2:/Table/68/1/5{-/7}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n2,s2):2] next=3
I190626 00:54:19.364899 621085 storage/store.go:2522 [n1,replicaGC,s1,r38/1:/Table/68/1/5{-/7}] removing replica r38/1
I190626 00:54:19.366733 621085 storage/replica_destroy.go:146 [n1,replicaGC,s1,r38/1:/Table/68/1/5{-/7}] removed 8 (0+8) keys in 1ms [clear=1ms commit=0ms]
TestRepartitioning/single_col_list_partitioning_-_DEFAULT/single_col_list_partitioning
...g replica r60/2
I190626 00:53:57.407930 587280 storage/replica_destroy.go:146 [n3,replicaGC,s3,r60/2:/Table/66/{1/5-2}] removed 8 (0+8) keys in 1ms [clear=1ms commit=0ms]
I190626 00:53:57.423338 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a > 4
E190626 00:53:57.470198 587612 storage/queue.go:1033 [n2,replicate,s2,r59/1:/Table/66/1/{4-5}] no removable replicas from range that needs a removal: [1*:18, 2:0]
I190626 00:53:57.478586 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:53:57.524553 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:53:57.553709 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:53:57.662911 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
E190626 00:53:57.669074 588040 storage/queue.go:1033 [n2,replicate,s2,r36/2:/Table/66/1/{3-4}] no removable replicas from range that needs a removal: [1:0, 2*:17]
I190626 00:53:57.728585 588092 storage/replica_command.go:933 [n2,replicate,s2,r36/2:/Table/66/1/{3-4}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r36:/Table/66/1/{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=29]
I190626 00:53:57.845255 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
I190626 00:53:57.890247 588092 storage/replica_raft.go:395 [n2,s2,r36/2:/Table/66/1/{3-4}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n2,s2):2] next=3
I190626 00:53:57.908188 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a > 4
I190626 00:53:57.938757 588475 storage/store.go:2522 [n1,replicaGC,s1,r36/1:/Table/66/1/{3-4}] removing replica r36/1
I190626 00:53:57.941432 588475 storage/replica_destroy.go:146 [n1,replicaGC,s1,r36/1:/Table/66/1/{3-4}] removed 5 (0+5) keys in 2ms [clear=0ms commit=1ms]
I190626 00:53:57.959425 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:53:57.997758 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
E190626 00:53:58.010137 588635 storage/queue.go:1033 [n3,replicate,s3,r59/2:/Table/66/1/{4-5}] no removable replicas from range that needs a removal: [1:0, 2*:21]
I190626 00:53:58.059104 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
I190626 00:53:58.206206 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:53:58.260710 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
I190626 00:53:58.332962 589286 storage/replica_command.go:933 [n3,replicate,s3,r59/2:/Table/66/1/{4-5}] change replicas (REMOVE_REPLICA (n2,s2):1): existing descriptor r59:/Table/66/1/{4-5} [(n2,s2):1, (n3,s3):2, next=3, gen=28]
I190626 00:53:58.448127 589286 storage/replica_raft.go:395 [n3,s3,r59/2:/Table/66/1/{4-5}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n3,s3):2] next=3
I190626 00:53:58.452404 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a > 4
I190626 00:53:58.519305 561246 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:53:58.544309 589528 storage/store.go:2522 [n2,replicaGC,s2,r59/1:/Table/66/1/{4-5}] removing replica r59/1
I190626 00:53:58.547350 589528 storage/replica_destroy.go:146 [n2,replicaGC,s2,r59/1:/Table/66/1/{4-5}] removed 6 (0+6) keys in 2ms [clear=1ms commit=0ms]
TestRepartitioning/multi_col_list_partitioning_-_DEFAULT/multi_col_list_partitioning_-_DEFAULT_DEFAULT
... query cache hit
[n1,client=127.0.0.1:49654,user=root] planning ends
[n1,client=127.0.0.1:49654,user=root] checking distributability
[n1,client=127.0.0.1:49654,user=root] will distribute plan: true
[n1,client=127.0.0.1:49654,user=root] execution starts: distributed engine
=== SPAN START: consuming rows ===
[n1,client=127.0.0.1:49654,user=root] creating DistSQL plan with isLocal=false
[n1,client=127.0.0.1:49654,user=root] querying next range at /Table/72/1/3/5
[n1,client=127.0.0.1:49654,user=root] running DistSQL plan
=== SPAN START: flow ===
[n1,client=127.0.0.1:49654,user=root] starting (0 processors, 0 startables)
=== SPAN START: table reader ===
cockroach.processorid: 0
cockroach.stat.tablereader.bytes.read: 0 B
cockroach.stat.tablereader.input.rows: 0
cockroach.stat.tablereader.stalltime: 3.395ms
[n1,client=127.0.0.1:49654,user=root] starting scan with limitBatches true
[n1,client=127.0.0.1:49654,user=root] Scan /Table/72/1/{3/5-5}
=== SPAN START: txn coordinator send ===
=== SPAN START: dist sender send ===
[n1,client=127.0.0.1:49654,user=root,txn=40dbb4fc] querying next range at /Table/72/1/3/5
[n1,client=127.0.0.1:49654,user=root,txn=40dbb4fc] r105: sending batch 1 Scan to (n1,s1):2
[n1,client=127.0.0.1:49654,user=root,txn=40dbb4fc] sending request to local client
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n1] 1 Scan
[n1,s1] executing 1 requests
[n1,s1,r105/2:/Table/72/1/{3/5-5}] read-only path
[n1,s1,r105/2:/Table/72/1/{3/5-5}] read has no clock uncertainty
[n1,s1,r105/2:/Table/72/1/{3/5-5}] acquire latches
[n1,s1,r105/2:/Table/72/1/{3/5-5}] waited 130.879µs to acquire latches
[n1,s1,r105/2:/Table/72/1/{3/5-5}] waiting for read lock
[n1,s1,r105/2:/Table/72/1/{3/5-5}] read completed
=== SPAN START: count rows ===
cockroach.processorid: 1
cockroach.stat.aggregator.input.rows: 0
cockroach.stat.aggregator.mem.max: 0 B
cockroach.stat.aggregator.stalltime: 625µs
[n1,client=127.0.0.1:49654,user=root] execution ends
[n1,client=127.0.0.1:49654,user=root] rows affected: 1
[n1,client=127.0.0.1:49654,user=root] AutoCommit. err: <nil>
[n1,client=127.0.0.1:49654,user=root] releasing 1 tables
=== SPAN START: exec cmd: exec stmt ===
[n1,client=127.0.0.1:49654,user=root] [NoTxn pos:2740] executing ExecStmt: SET TRACING = off
[n1,client=127.0.0.1:49654,user=root] executing: SET TRACING = off in state: NoTxn
I190626 00:55:14.610414 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a > 5
I190626 00:55:14.685492 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE (a, b) < (3, 4)
E190626 00:55:14.831626 697143 storage/queue.go:1033 [n2,replicate,s2,r105/3:/Table/72/1/{3/5-5}] no removable replicas from range that needs a removal: [2:0, 3*:37]
I190626 00:55:14.832955 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a = 3 AND b = 4
I190626 00:55:14.879263 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE (a, b) > (3, 4) AND a < 5
I190626 00:55:14.930776 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a = 5 AND b < 7
I190626 00:55:14.970777 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a = 5 AND b = 7
I190626 00:55:15.034428 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a = 5 AND b = 8
I190626 00:55:15.083566 655929 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT DEFAULT" WHERE a = 5 AND b > 8
TestRepartitioning/multi_col_range_partitioning/multi_col_range_partitioning_-_MAXVALUE
...Open pos:4140] executing ExecStmt: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE (a >= 4) AND ((a, b) < (5, 6))
[n1,client=127.0.0.1:49654,user=root] executing: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE (a >= 4) AND ((a, b) < (5, 6)) in state: Open
[n1,client=127.0.0.1:49654,user=root] planning starts: SELECT
[n1,client=127.0.0.1:49654,user=root] generating optimizer plan
[n1,client=127.0.0.1:49654,user=root] added table 'data.public."multi col range partitioning - MAXVALUE"' to table collection
[n1,client=127.0.0.1:49654,user=root] query cache hit
[n1,client=127.0.0.1:49654,user=root] planning ends
[n1,client=127.0.0.1:49654,user=root] checking distributability
[n1,client=127.0.0.1:49654,user=root] will distribute plan: true
[n1,client=127.0.0.1:49654,user=root] execution starts: distributed engine
=== SPAN START: consuming rows ===
[n1,client=127.0.0.1:49654,user=root] creating DistSQL plan with isLocal=false
[n1,client=127.0.0.1:49654,user=root] querying next range at /Table/80/1/4
[n1,client=127.0.0.1:49654,user=root] running DistSQL plan
=== SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
=== SPAN START: outbox ===
cockroach.stat.outbox.bytes_sent: ࢤ
cockroach.streamid: 1
=== SPAN START: [async] drain ===
=== SPAN START: table reader ===
cockroach.processorid: 0
cockroach.stat.tablereader.bytes.read: 0 B
cockroach.stat.tablereader.input.rows: 0
cockroach.stat.tablereader.stalltime: 7.309ms
[n3] starting scan with limitBatches true
[n3] Scan /Table/80/1/{4-5/5/#}
=== SPAN START: txn coordinator send ===
=== SPAN START: dist sender send ===
[n3,txn=46c2ff07] querying next range at /Table/80/1/4
[n3,txn=46c2ff07] r113: sending batch 1 Scan to (n3,s3):1
[n3,txn=46c2ff07] sending request to local client
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n3] 1 Scan
[n3,s3] executing 1 requests
[n3,s3,r113/1:/Table/80/1/{4-5/6}] read-only path
[n3,s3,r113/1:/Table/80/1/{4-5/6}] acquire latches
[n3,s3,r113/1:/Table/80/1/{4-5/6}] waited 95.053µs to acquire latches
[n3,s3,r113/1:/Table/80/1/{4-5/6}] waiting for read lock
[n3,s3,r113/1:/Table/80/1/{4-5/6}] read completed
=== SPAN START: count rows ===
cockroach.processorid: 1
cockroach.stat.aggregator.input.rows: 0
cockroach.stat.aggregator.mem.max: 0 B
cockroach.stat.aggregator.stalltime: 415µs
[n3] Consumer sent handshake. Consuming flow scheduled: false
=== SPAN START: flow ===
[n1,client=127.0.0.1:49654,user=root] starting (0 processors, 0 startables)
=== SPAN START: noop ===
cockroach.processorid: 2
[n1,client=127.0.0.1:49654,user=root] execution ends
[n1,client=127.0.0.1:49654,user=root] rows affected: 1
[n1,client=127.0.0.1:49654,user=root] AutoCommit. err: <nil>
[n1,client=127.0.0.1:49654,user=root] releasing 1 tables
=== SPAN START: exec cmd: exec stmt ===
[n1,client=127.0.0.1:49654,user=root] [NoTxn pos:4141] executing ExecStmt: SET TRACING = off
[n1,client=127.0.0.1:49654,user=root] executing: SET TRACING = off in state: NoTxn
I190626 00:56:37.052145 784330 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE (a, b) >= (5, 7)
I190626 00:56:37.146225 784330 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE a < 3
I190626 00:56:37.305028 784330 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE a >= 3 AND a < 4
I190626 00:56:37.388451 784330 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE a >= 4 AND (a, b) < (5, 6)
I190626 00:56:37.480969 784330 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE" WHERE (a, b) >= (5, 6) AND (a, b) < (5, 7)
TestRepartitioning/single_col_range_partitioning_-_MAXVALUE/single_col_range_partitioning
...2:0]
I190626 00:56:14.048539 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
I190626 00:56:14.113035 782111 storage/replica_raft.go:395 [n3,s3,r64/3:/Table/68{-/1}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n3,s3):3] next=4
E190626 00:56:14.292156 782633 storage/queue.go:1033 [n1,replicate,s1,r129/2:/Table/78/{1/4-2}] no removable replicas from range that needs a removal: [1:0, 2*:29]
I190626 00:56:14.335779 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:56:14.376970 782571 storage/store.go:2522 [n2,replicaGC,s2,r64/1:/Table/68{-/1}] removing replica r64/1
I190626 00:56:14.380499 782571 storage/replica_destroy.go:146 [n2,replicaGC,s2,r64/1:/Table/68{-/1}] removed 6 (0+6) keys in 1ms [clear=1ms commit=0ms]
I190626 00:56:14.387603 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
I190626 00:56:14.500578 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:56:14.533782 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
I190626 00:56:14.589953 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:56:14.715913 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
I190626 00:56:14.832456 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:56:14.838118 783417 storage/replica_command.go:933 [n3,replicate,s3,r72/2:/Table/78/1/{3-4}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r72:/Table/78/1/{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=56]
I190626 00:56:15.042197 783456 storage/replica_command.go:933 [n1,replicate,s1,r129/2:/Table/78/{1/4-2}] change replicas (REMOVE_REPLICA (n2,s2):1): existing descriptor r129:/Table/78/{1/4-2} [(n2,s2):1, (n1,s1):2, next=3, gen=60]
I190626 00:56:15.105712 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
I190626 00:56:15.140541 783417 storage/replica_raft.go:395 [n3,s3,r72/2:/Table/78/1/{3-4}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n3,s3):2] next=3
I190626 00:56:15.297139 783861 storage/store.go:2522 [n1,replicaGC,s1,r72/1:/Table/78/1/{3-4}] removing replica r72/1
I190626 00:56:15.309764 783861 storage/replica_destroy.go:146 [n1,replicaGC,s1,r72/1:/Table/78/1/{3-4}] removed 6 (0+6) keys in 1ms [clear=1ms commit=0ms]
I190626 00:56:15.340110 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:56:15.380436 479032 server/status/runtime.go:498 [n3] runtime stats: 1.7 GiB RSS, 687 goroutines, 92 MiB/72 MiB/204 MiB GO alloc/idle/total, 148 MiB/197 MiB CGO alloc/total, 2204.7 CGO/sec, 187.8/23.4 %(u/s)time, 0.5 %gc (5x), 2.6 MiB/2.6 MiB (r/w)net
I190626 00:56:15.383411 783456 storage/replica_raft.go:395 [n1,s1,r129/2:/Table/78/{1/4-2}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n1,s1):2] next=3
I190626 00:56:15.500565 784207 storage/store.go:2522 [n2,replicaGC,s2,r129/1:/Table/78/{1/4-2}] removing replica r129/1
I190626 00:56:15.534157 784207 storage/replica_destroy.go:146 [n2,replicaGC,s2,r129/1:/Table/78/{1/4-2}] removed 9 (0+9) keys in 32ms [clear=1ms commit=32ms]
I190626 00:56:15.609288 758744 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 4
E190626 00:56:15.655832 784389 storage/queue.go:1033 [n3,replicate,s3,r21/7:/Table/5{4-6}] no removable replicas from range that needs a removal: [6:0, 7*:68]
TestRepartitioning/multi_col_range_partitioning_-_MAXVALUE/multi_col_range_partitioning
...7.0.0.1:49654,user=root] generating optimizer plan
[n1,client=127.0.0.1:49654,user=root] added table 'data.public."multi col range partitioning"' to table collection
[n1,client=127.0.0.1:49654,user=root] query cache hit
[n1,client=127.0.0.1:49654,user=root] planning ends
[n1,client=127.0.0.1:49654,user=root] checking distributability
[n1,client=127.0.0.1:49654,user=root] will distribute plan: true
[n1,client=127.0.0.1:49654,user=root] execution starts: distributed engine
=== SPAN START: consuming rows ===
[n1,client=127.0.0.1:49654,user=root] creating DistSQL plan with isLocal=false
[n1,client=127.0.0.1:49654,user=root] querying next range at /Table/82/1
[n1,client=127.0.0.1:49654,user=root] running DistSQL plan
=== SPAN START: flow ===
[n1,client=127.0.0.1:49654,user=root] starting (0 processors, 0 startables)
=== SPAN START: table reader ===
cockroach.processorid: 0
cockroach.stat.tablereader.bytes.read: 0 B
cockroach.stat.tablereader.input.rows: 0
cockroach.stat.tablereader.stalltime: 2.219ms
[n1,client=127.0.0.1:49654,user=root] starting scan with limitBatches true
[n1,client=127.0.0.1:49654,user=root] Scan /Table/82/1{-/3/3/#}
=== SPAN START: txn coordinator send ===
=== SPAN START: dist sender send ===
[n1,client=127.0.0.1:49654,user=root,txn=a76f6b07] querying next range at /Table/82/1
[n1,client=127.0.0.1:49654,user=root,txn=a76f6b07] r138: sending batch 1 Scan to (n1,s1):3
[n1,client=127.0.0.1:49654,user=root,txn=a76f6b07] sending request to local client
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n1] 1 Scan
[n1,s1] executing 1 requests
[n1,s1,r138/3:/Table/82/1{-/3/4}] read-only path
[n1,s1,r138/3:/Table/82/1{-/3/4}] read has no clock uncertainty
[n1,s1,r138/3:/Table/82/1{-/3/4}] acquire latches
[n1,s1,r138/3:/Table/82/1{-/3/4}] waited 65.341µs to acquire latches
[n1,s1,r138/3:/Table/82/1{-/3/4}] waiting for read lock
[n1,s1,r138/3:/Table/82/1{-/3/4}] read completed
=== SPAN START: count rows ===
cockroach.processorid: 1
cockroach.stat.aggregator.input.rows: 0
cockroach.stat.aggregator.mem.max: 0 B
cockroach.stat.aggregator.stalltime: 393µs
[n1,client=127.0.0.1:49654,user=root] execution ends
[n1,client=127.0.0.1:49654,user=root] rows affected: 1
[n1,client=127.0.0.1:49654,user=root] AutoCommit. err: <nil>
[n1,client=127.0.0.1:49654,user=root] releasing 1 tables
=== SPAN START: exec cmd: exec stmt ===
[n1,client=127.0.0.1:49654,user=root] [NoTxn pos:4560] executing ExecStmt: SET TRACING = off
[n1,client=127.0.0.1:49654,user=root] executing: SET TRACING = off in state: NoTxn
I190626 00:56:58.690918 816058 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning" WHERE (a, b) < (3, 4)
I190626 00:56:58.768650 847444 storage/replica_command.go:933 [n2,replicate,s2,r138/4:/Table/82/1{-/3/4}] change replicas (REMOVE_REPLICA (n1,s1):3): existing descriptor r138:/Table/82/1{-/3/4} [(n1,s1):3, (n2,s2):4, next=5, gen=69]
I190626 00:56:58.849651 816058 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning" WHERE (a, b) >= (3, 4) AND (a, b) < (5, 6)
I190626 00:56:58.903427 847444 storage/replica_raft.go:395 [n2,s2,r138/4:/Table/82/1{-/3/4}] proposing REMOVE_REPLICA((n1,s1):3): updated=[(n2,s2):4] next=5
I190626 00:56:58.924459 816058 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning" WHERE (a, b) >= (5, 6) AND (a, b) < (5, 7)
I190626 00:56:58.985330 816058 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning" WHERE (a, b) >= (5, 7)
I190626 00:56:59.039064 847760 storage/store.go:2522 [n1,replicaGC,s1,r138/3:/Table/82/1{-/3/4}] removing replica r138/3
I190626 00:56:59.054929 847760 storage/replica_destroy.go:146 [n1,replicaGC,s1,r138/3:/Table/82/1{-/3/4}] removed 9 (0+9) keys in 15ms [clear=15ms commit=0ms]
TestRepartitioning
...s2):?: kv pairs: 11, log entries: 0, rate-limit: 8.0 MiB/sec, 0.01s
I190626 00:52:44.655881 489599 storage/replica_raftstorage.go:808 [n2,s2,r19/?:{-}] applying PREEMPTIVE snapshot at index 16 (id=10bebdf5, encoded size=727, 1 rocksdb batches, 0 log entries)
I190626 00:52:44.658598 489599 storage/replica_raftstorage.go:814 [n2,s2,r19/?:/Table/2{3-4}] applied PREEMPTIVE snapshot in 2ms [clear=0ms batch=0ms entries=0ms commit=1ms]
I190626 00:52:44.675001 475662 storage/replica_command.go:933 [n1,replicate,s1,r19/1:/Table/2{3-4}] change replicas (ADD_REPLICA (n2,s2):3): existing descriptor r19:/Table/2{3-4} [(n1,s1):1, (n3,s3):2, next=3, gen=0]
I190626 00:52:44.829008 475662 storage/replica_raft.go:395 [n1,s1,r19/1:/Table/2{3-4}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I190626 00:52:44.911279 475662 storage/store_snapshot.go:774 [n1,replicate,s1,r18/1:/Table/2{2-3}] sending PREEMPTIVE snapshot 0d13e6b6 at applied index 13
I190626 00:52:44.918314 475662 storage/store_snapshot.go:817 [n1,replicate,s1,r18/1:/Table/2{2-3}] streamed snapshot to (n3,s3):?: kv pairs: 5, log entries: 0, rate-limit: 8.0 MiB/sec, 0.04s
I190626 00:52:44.921947 489907 storage/replica_raftstorage.go:808 [n3,s3,r18/?:{-}] applying PREEMPTIVE snapshot at index 13 (id=0d13e6b6, encoded size=234, 1 rocksdb batches, 0 log entries)
I190626 00:52:44.925875 489907 storage/replica_raftstorage.go:814 [n3,s3,r18/?:/Table/2{2-3}] applied PREEMPTIVE snapshot in 4ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I190626 00:52:44.941151 475662 storage/replica_command.go:933 [n1,replicate,s1,r18/1:/Table/2{2-3}] change replicas (ADD_REPLICA (n3,s3):2): existing descriptor r18:/Table/2{2-3} [(n1,s1):1, next=2, gen=0]
I190626 00:52:45.033204 475662 storage/replica_raft.go:395 [n1,s1,r18/1:/Table/2{2-3}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
I190626 00:52:45.107599 475662 storage/store_snapshot.go:774 [n1,replicate,s1,r18/1:/Table/2{2-3}] sending PREEMPTIVE snapshot a00b47d5 at applied index 15
I190626 00:52:45.108854 475662 storage/store_snapshot.go:817 [n1,replicate,s1,r18/1:/Table/2{2-3}] streamed snapshot to (n2,s2):?: kv pairs: 7, log entries: 0, rate-limit: 8.0 MiB/sec, 0.05s
I190626 00:52:45.124719 490111 storage/replica_raftstorage.go:808 [n2,s2,r18/?:{-}] applying PREEMPTIVE snapshot at index 15 (id=a00b47d5, encoded size=568, 1 rocksdb batches, 0 log entries)
I190626 00:52:45.140758 490111 storage/replica_raftstorage.go:814 [n2,s2,r18/?:/Table/2{2-3}] applied PREEMPTIVE snapshot in 16ms [clear=0ms batch=0ms entries=0ms commit=6ms]
I190626 00:52:45.147694 475662 storage/replica_command.go:933 [n1,replicate,s1,r18/1:/Table/2{2-3}] change replicas (ADD_REPLICA (n2,s2):3): existing descriptor r18:/Table/2{2-3} [(n1,s1):1, (n3,s3):2, next=3, gen=0]
I190626 00:52:45.220157 479032 server/status/runtime.go:498 [n3] runtime stats: 1.5 GiB RSS, 679 goroutines, 86 MiB/84 MiB/204 MiB GO alloc/idle/total, 84 MiB/128 MiB CGO alloc/total, 0.0 CGO/sec, 0.0/0.0 %(u/s)time, 0.0 %gc (315x), 2.9 MiB/2.9 MiB (r/w)net
I190626 00:52:45.299578 475662 storage/replica_raft.go:395 [n1,s1,r18/1:/Table/2{2-3}] proposing ADD_REPLICA((n2,s2):3): updated=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I190626 00:52:45.315282 475662 storage/queue.go:1133 [n1,replicate] purgatory is now empty
I190626 00:52:45.540425 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "create_database", target: 52, info: {DatabaseName:data Statement:CREATE DATABASE data User:root}
I190626 00:52:45.817042 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "set_cluster_setting", target: 0, info: {SettingName:server.declined_reservation_timeout Value:00:00:00 User:root}
I190626 00:52:45.967030 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "set_cluster_setting", target: 0, info: {SettingName:server.failed_reservation_timeout Value:00:00:00 User:root}
TestRepartitioning/unpartitioned/single_col_range_partitioning
...lookup=/Meta2/Table/60/1/3/NULL] looked up range descriptor: r1:/{Min-System/NodeLiveness} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=0]
[n2,txn=7c80621e,range-lookup=/Meta2/Table/60/1/3/NULL] r1: sending batch 1 Scan to (n1,s1):1
[n2,txn=7c80621e,range-lookup=/Meta2/Table/60/1/3/NULL] sending request to 127.0.0.1:34527
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n1] 1 Scan
[n1,s1] executing 1 requests
[n1,s1,r1/1:/{Min-System/NodeL…}] read-only path
[n1,s1,r1/1:/{Min-System/NodeL…}] acquire latches
[n1,s1,r1/1:/{Min-System/NodeL…}] operation accepts inconsistent results
[n1,s1,r1/1:/{Min-System/NodeL…}] waiting for read lock
[n1,s1,r1/1:/{Min-System/NodeL…}] read completed
[n2,txn=7c80621e,range-lookup=/Table/60/1/3] looked up range descriptor: r1:/{Min-System/NodeLiveness} [(n1,s1):1, (n3,s3):2, (n2,s2):3, next=4, gen=0]
[n2,txn=7c80621e,range-lookup=/Table/60/1/3] r1: sending batch 1 Scan to (n1,s1):1
[n2,txn=7c80621e,range-lookup=/Table/60/1/3] sending request to 127.0.0.1:34527
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n1] 1 Scan
[n1,s1] executing 1 requests
[n1,s1,r1/1:/{Min-System/NodeL…}] read-only path
[n1,s1,r1/1:/{Min-System/NodeL…}] acquire latches
[n1,s1,r1/1:/{Min-System/NodeL…}] operation accepts inconsistent results
[n1,s1,r1/1:/{Min-System/NodeL…}] waiting for read lock
[n1,s1,r1/1:/{Min-System/NodeL…}] read completed
[n2,txn=7c80621e] looked up range descriptor: r43:/Table/60/1/{3-4} [(n2,s2):1, (n3,s3):2, next=3, gen=16]
[n2,txn=7c80621e] r43: sending batch 1 Scan to (n3,s3):2
[n2,txn=7c80621e] sending request to 127.0.0.1:34443
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n3] 1 Scan
[n3,s3] executing 1 requests
[n3,s3,r43/2:/Table/60/1/{3-4}] read-only path
[n3,s3,r43/2:/Table/60/1/{3-4}] acquire latches
[n3,s3,r43/2:/Table/60/1/{3-4}] waited 7.025512ms to acquire latches
[n3,s3,r43/2:/Table/60/1/{3-4}] waiting for read lock
[n3,s3,r43/2:/Table/60/1/{3-4}] read completed
=== SPAN START: count rows ===
cockroach.processorid: 1
cockroach.stat.aggregator.input.rows: 0
cockroach.stat.aggregator.mem.max: 0 B
cockroach.stat.aggregator.stalltime: 10.246ms
[n1,client=127.0.0.1:49654,user=root] execution ends
[n1,client=127.0.0.1:49654,user=root] rows affected: 1
[n1,client=127.0.0.1:49654,user=root] AutoCommit. err: <nil>
[n1,client=127.0.0.1:49654,user=root] releasing 1 tables
=== SPAN START: exec cmd: exec stmt ===
[n1,client=127.0.0.1:49654,user=root] [NoTxn pos:434] executing ExecStmt: SET TRACING = off
[n1,client=127.0.0.1:49654,user=root] executing: SET TRACING = off in state: NoTxn
I190626 00:53:10.783809 511193 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a < 3
E190626 00:53:10.976318 523122 storage/queue.go:1033 [n1,replicate,s1,r33/3:/Table/{58/2-60}] no removable replicas from range that needs a removal: [2:0, 3*:31]
I190626 00:53:10.986308 511193 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 3 AND a < 4
I190626 00:53:10.989943 523211 storage/store.go:2522 [n2,replicaGC,s2,r43/1:/Table/60/1/{3-4}] removing replica r43/1
I190626 00:53:10.992936 523211 storage/replica_destroy.go:146 [n2,replicaGC,s2,r43/1:/Table/60/1/{3-4}] removed 6 (0+6) keys in 2ms [clear=2ms commit=0ms]
I190626 00:53:11.337022 511193 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning" WHERE a >= 4
I190626 00:53:11.389847 523570 storage/replica_command.go:933 [n1,replicate,s1,r33/3:/Table/{58/2-60}] change replicas (REMOVE_REPLICA (n2,s2):2): existing descriptor r33:/Table/{58/2-60} [(n2,s2):2, (n1,s1):3, next=4, gen=13]
TestRepartitioning/unpartitioned/single_col_list_partitioning_-_DEFAULT
...removable replicas from range that needs a removal: [1*:18, 2:0]
I190626 00:52:59.713630 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
I190626 00:52:59.819759 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
I190626 00:52:59.923398 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a > 5
I190626 00:52:59.949647 510315 storage/replica_command.go:933 [n3,replicate,s3,r30/2:/Table/58/1/{5-6}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r30:/Table/58/1/{5-6} [(n1,s1):1, (n3,s3):2, next=3, gen=11]
I190626 00:53:00.011041 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
E190626 00:53:00.024482 510486 storage/queue.go:1033 [n2,replicate,s2,r29/2:/Table/58/1/{4-5}] no removable replicas from range that needs a removal: [1:0, 2*:20]
I190626 00:53:00.095581 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
W190626 00:53:00.105165 17 storage/engine/rocksdb.go:117 [rocksdb] [/go/src/github.com/cockroachdb/cockroach/c-deps/rocksdb/db/version_set.cc:2566] More existing levels in DB than needed. max_bytes_for_level_multiplier may not be guaranteed.
I190626 00:53:00.198168 510576 storage/replica_command.go:933 [n2,replicate,s2,r29/2:/Table/58/1/{4-5}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r29:/Table/58/1/{4-5} [(n1,s1):1, (n2,s2):2, next=3, gen=10]
I190626 00:53:00.368743 510315 storage/replica_raft.go:395 [n3,s3,r30/2:/Table/58/1/{5-6}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n3,s3):2] next=3
I190626 00:53:00.449204 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 5
I190626 00:53:00.501674 475372 server/status/runtime.go:498 [n1] runtime stats: 1.5 GiB RSS, 690 goroutines, 119 MiB/58 MiB/204 MiB GO alloc/idle/total, 94 MiB/139 MiB CGO alloc/total, 2252.1 CGO/sec, 176.7/19.0 %(u/s)time, 1.0 %gc (5x), 2.6 MiB/2.6 MiB (r/w)net
I190626 00:53:00.646955 510674 storage/store.go:2522 [n1,replicaGC,s1,r30/1:/Table/58/1/{5-6}] removing replica r30/1
I190626 00:53:00.652833 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a > 5
I190626 00:53:00.658552 510674 storage/replica_destroy.go:146 [n1,replicaGC,s1,r30/1:/Table/58/1/{5-6}] removed 6 (0+6) keys in 1ms [clear=0ms commit=0ms]
I190626 00:53:00.685847 510576 storage/replica_raft.go:395 [n2,s2,r29/2:/Table/58/1/{4-5}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n2,s2):2] next=3
E190626 00:53:00.739293 510989 storage/queue.go:1033 [n2,replicate,s2,r28/2:/Table/58{-/1}] no removable replicas from range that needs a removal: [1:0, 2*:24]
I190626 00:53:00.787394 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
I190626 00:53:00.828215 511018 storage/store.go:2522 [n1,replicaGC,s1,r29/1:/Table/58/1/{4-5}] removing replica r29/1
I190626 00:53:00.832761 511018 storage/replica_destroy.go:146 [n1,replicaGC,s1,r29/1:/Table/58/1/{4-5}] removed 6 (0+6) keys in 1ms [clear=1ms commit=0ms]
I190626 00:53:00.868848 501736 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
E190626 00:53:00.887651 511352 storage/queue.go:1033 [n2,replicate,s2,r33/2:/{Table/58/2-Max}] no removable replicas from range that needs a removal: [1:17, 2*:17]
I190626 00:53:00.949980 511424 storage/replica_command.go:933 [n3,replicate,s3,r27/2:/Table/5{6/2-8}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r27:/Table/5{6/2-8} [(n1,s1):1, (n3,s3):2, next=3, gen=8]
TestRepartitioning/multi_col_range_partitioning_-_MAXVALUE/multi_col_range_partitioning_-_MAXVALUE_MAXVALUE
... [n2,s2,r1/3:/{Min-System/NodeL…}] waiting for read lock
[n2,s2,r1/3:/{Min-System/NodeL…}] read completed
[n1,client=127.0.0.1:49654,user=root] looked up range descriptor with shared request: r146:/Table/84/1/5/{6-7} [(n2,s2):1, (n1,s1):3, next=4, gen=72]
[n1,client=127.0.0.1:49654,user=root] running DistSQL plan
=== SPAN START: flow ===
[n1,client=127.0.0.1:49654,user=root] starting (0 processors, 0 startables)
=== SPAN START: table reader ===
cockroach.processorid: 0
cockroach.stat.tablereader.bytes.read: 0 B
cockroach.stat.tablereader.input.rows: 0
cockroach.stat.tablereader.stalltime: 5.679ms
[n1,client=127.0.0.1:49654,user=root] starting scan with limitBatches false
[n1,client=127.0.0.1:49654,user=root] Scan /Table/84/1/5/6{-/#}
=== SPAN START: txn coordinator send ===
=== SPAN START: dist sender send ===
[n1,client=127.0.0.1:49654,user=root,txn=cd698f9f] querying next range at /Table/84/1/5/6
[n1,client=127.0.0.1:49654,user=root,txn=cd698f9f] r146: sending batch 1 Scan to (n1,s1):3
[n1,client=127.0.0.1:49654,user=root,txn=cd698f9f] sending request to local client
=== SPAN START: /cockroach.roachpb.Internal/Batch ===
[n1] 1 Scan
[n1,s1] executing 1 requests
[n1,s1,r146/3:/Table/84/1/5/{6-7}] read-only path
[n1,s1,r146/3:/Table/84/1/5/{6-7}] read has no clock uncertainty
[n1,s1,r146/3:/Table/84/1/5/{6-7}] acquire latches
[n1,s1,r146/3:/Table/84/1/5/{6-7}] waited 98.647µs to acquire latches
[n1,s1,r146/3:/Table/84/1/5/{6-7}] waiting for read lock
[n1,s1,r146/3:/Table/84/1/5/{6-7}] read completed
=== SPAN START: count rows ===
cockroach.processorid: 1
cockroach.stat.aggregator.input.rows: 0
cockroach.stat.aggregator.mem.max: 0 B
cockroach.stat.aggregator.stalltime: 343µs
[n1,client=127.0.0.1:49654,user=root] execution ends
[n1,client=127.0.0.1:49654,user=root] rows affected: 1
[n1,client=127.0.0.1:49654,user=root] AutoCommit. err: <nil>
[n1,client=127.0.0.1:49654,user=root] releasing 1 tables
=== SPAN START: exec cmd: exec stmt ===
[n1,client=127.0.0.1:49654,user=root] [NoTxn pos:4872] executing ExecStmt: SET TRACING = off
[n1,client=127.0.0.1:49654,user=root] executing: SET TRACING = off in state: NoTxn
I190626 00:57:18.396297 847794 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) < (3, 4)
I190626 00:57:18.445971 877204 storage/replica_raft.go:395 [n1,s1,r146/3:/Table/84/1/5/{6-7}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n1,s1):3] next=4
I190626 00:57:18.449658 847794 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) >= (3, 4) AND a < 4
I190626 00:57:18.606343 847794 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE a >= 4 AND (a, b) < (5, 6)
I190626 00:57:18.665915 877718 storage/store.go:2522 [n2,replicaGC,s2,r146/1:/Table/84/1/5/{6-7}] removing replica r146/1
I190626 00:57:18.729377 877718 storage/replica_destroy.go:146 [n2,replicaGC,s2,r146/1:/Table/84/1/5/{6-7}] removed 6 (0+6) keys in 52ms [clear=35ms commit=17ms]
I190626 00:57:18.763209 878075 storage/replica_command.go:933 [n2,replicate,s2,r80/3:/Table/84/{1/5/7-2}] change replicas (REMOVE_REPLICA (n1,s1):2): existing descriptor r80:/Table/84/{1/5/7-2} [(n1,s1):2, (n2,s2):3, next=4, gen=72]
I190626 00:57:18.787225 847794 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) >= (5, 6) AND (a, b) < (5, 7)
I190626 00:57:18.863087 847794 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col range partitioning - MAXVALUE MAXVALUE" WHERE (a, b) >= (5, 7)
I190626 00:57:18.877205 878075 storage/replica_raft.go:395 [n2,s2,r80/3:/Table/84/{1/5/7-2}] proposing REMOVE_REPLICA((n1,s1):2): updated=[(n2,s2):3] next=4
TestRepartitioning/unpartitioned/single_col_range_partitioning_-_MAXVALUE
...ed PREEMPTIVE snapshot in 40ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I190626 00:53:19.871627 536306 storage/replica_command.go:933 [n2,replicate,s2,r49/1:/Table/62/{1/5-2}] change replicas (ADD_REPLICA (n3,s3):2): existing descriptor r49:/Table/62/{1/5-2} [(n2,s2):1, next=2, gen=22]
I190626 00:53:19.947951 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:53:20.059276 536306 storage/replica_raft.go:395 [n2,s2,r49/1:/Table/62/{1/5-2}] proposing ADD_REPLICA((n3,s3):2): updated=[(n2,s2):1 (n3,s3):2] next=3
E190626 00:53:20.073646 536306 storage/queue.go:1033 [n2,replicate,s2,r49/1:/Table/62/{1/5-2}] no removable replicas from range that needs a removal: [1*:17, 2:0]
I190626 00:53:20.079373 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:53:20.307186 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
E190626 00:53:20.433779 537101 storage/queue.go:1033 [n2,replicate,s2,r49/1:/Table/62/{1/5-2}] no removable replicas from range that needs a removal: [1*:17, 2:0]
I190626 00:53:20.486115 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:53:20.510909 475372 server/status/runtime.go:498 [n1] runtime stats: 1.5 GiB RSS, 685 goroutines, 71 MiB/96 MiB/204 MiB GO alloc/idle/total, 99 MiB/147 MiB CGO alloc/total, 1781.9 CGO/sec, 176.3/20.1 %(u/s)time, 0.5 %gc (5x), 3.5 MiB/3.5 MiB (r/w)net
E190626 00:53:20.606084 537325 storage/queue.go:1033 [n1,replicate,s1,r47/2:/Table/62/1{-/4}] no removable replicas from range that needs a removal: [1:0, 2*:20]
I190626 00:53:20.633011 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:53:20.814574 537771 storage/replica_command.go:933 [n1,replicate,s1,r47/2:/Table/62/1{-/4}] change replicas (REMOVE_REPLICA (n2,s2):1): existing descriptor r47:/Table/62/1{-/4} [(n2,s2):1, (n1,s1):2, next=3, gen=20]
I190626 00:53:20.822200 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:53:20.963292 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
E190626 00:53:21.065004 538074 storage/queue.go:1033 [n3,replicate,s3,r49/2:/Table/62/{1/5-2}] no removable replicas from range that needs a removal: [1:0, 2*:20]
I190626 00:53:21.068100 537771 storage/replica_raft.go:395 [n1,s1,r47/2:/Table/62/1{-/4}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n1,s1):2] next=3
I190626 00:53:21.222164 537969 storage/store.go:2522 [n2,replicaGC,s2,r47/1:/Table/62/1{-/4}] removing replica r47/1
I190626 00:53:21.223826 537969 storage/replica_destroy.go:146 [n2,replicaGC,s2,r47/1:/Table/62/1{-/4}] removed 5 (0+5) keys in 1ms [clear=0ms commit=0ms]
I190626 00:53:21.318829 538408 storage/replica_command.go:933 [n3,replicate,s3,r49/2:/Table/62/{1/5-2}] change replicas (REMOVE_REPLICA (n2,s2):1): existing descriptor r49:/Table/62/{1/5-2} [(n2,s2):1, (n3,s3):2, next=3, gen=22]
I190626 00:53:21.323564 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:53:21.380391 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:53:21.470892 523961 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:53:21.519681 538408 storage/replica_raft.go:395 [n3,s3,r49/2:/Table/62/{1/5-2}] proposing REMOVE_REPLICA((n2,s2):1): updated=[(n3,s3):2] next=3
TestRepartitioning/unpartitioned/single_col_list_partitioning
...626 00:52:52.594226 500033 storage/replica_command.go:933 [n1,replicate,s1,r25/1:/Table/56/1/{4-5}] change replicas (ADD_REPLICA (n3,s3):2): existing descriptor r25:/Table/56/1/{4-5} [(n1,s1):1, next=2, gen=6]
I190626 00:52:52.595351 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:52:52.666785 500033 storage/replica_raft.go:395 [n1,s1,r25/1:/Table/56/1/{4-5}] proposing ADD_REPLICA((n3,s3):2): updated=[(n1,s1):1 (n3,s3):2] next=3
E190626 00:52:52.671963 500033 storage/queue.go:1033 [n1,replicate,s1,r25/1:/Table/56/1/{4-5}] no removable replicas from range that needs a removal: [1*:17, 2:0]
I190626 00:52:52.676718 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:52:52.746543 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
E190626 00:52:52.765086 500397 storage/queue.go:1033 [n1,replicate,s1,r22/1:/Table/56{-/1}] no removable replicas from range that needs a removal: [1*:19, 3:0]
I190626 00:52:52.797105 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:52:52.825422 500466 storage/replica_command.go:933 [n2,replicate,s2,r24/2:/Table/56/1/{3-4}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r24:/Table/56/1/{3-4} [(n1,s1):1, (n2,s2):2, next=3, gen=5]
E190626 00:52:52.875937 500618 storage/queue.go:1033 [n1,replicate,s1,r25/1:/Table/56/1/{4-5}] no removable replicas from range that needs a removal: [1*:17, 2:0]
I190626 00:52:53.026210 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:52:53.058439 500466 storage/replica_raft.go:395 [n2,s2,r24/2:/Table/56/1/{3-4}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n2,s2):2] next=3
I190626 00:52:53.087869 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:52:53.241801 500716 storage/store.go:2522 [n1,replicaGC,s1,r24/1:/Table/56/1/{3-4}] removing replica r24/1
I190626 00:52:53.243438 500716 storage/replica_destroy.go:146 [n1,replicaGC,s1,r24/1:/Table/56/1/{3-4}] removed 5 (0+5) keys in 1ms [clear=0ms commit=0ms]
E190626 00:52:53.260515 500965 storage/queue.go:1033 [n1,replicate,s1,r22/1:/Table/56{-/1}] no removable replicas from range that needs a removal: [1*:19, 3:0]
I190626 00:52:53.279781 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
I190626 00:52:53.392625 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
E190626 00:52:53.420425 501181 storage/queue.go:1033 [n1,replicate,s1,r22/1:/Table/56{-/1}] no removable replicas from range that needs a removal: [1*:19, 3:0]
I190626 00:52:53.451836 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a < 3
I190626 00:52:53.485949 477827 server/status/runtime.go:498 [n2] runtime stats: 1.5 GiB RSS, 681 goroutines, 78 MiB/95 MiB/204 MiB GO alloc/idle/total, 89 MiB/134 MiB CGO alloc/total, 2304.3 CGO/sec, 171.5/17.3 %(u/s)time, 0.9 %gc (5x), 2.7 MiB/2.7 MiB (r/w)net
I190626 00:52:53.505892 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 3
I190626 00:52:53.571303 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a = 4
E190626 00:52:53.582777 501357 storage/queue.go:1033 [n3,replicate,s3,r25/2:/Table/56/1/{4-5}] no removable replicas from range that needs a removal: [1:0, 2*:20]
I190626 00:52:53.631927 492770 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning" WHERE a > 4
TestRepartitioning/single_col_range_partitioning/single_col_range_partitioning_-_MAXVALUE
...57032 storage/queue.go:1033 [n2,replicate,s2,r126/3:/Table/76/1/{4-5}] no removable replicas from range that needs a removal: [2:0, 3*:28]
I190626 00:55:56.892713 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:55:56.953847 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:55:57.036379 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:55:57.075685 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:55:57.174813 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:55:57.217570 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:55:57.303617 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:55:57.356088 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:55:57.432364 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:55:57.478016 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
E190626 00:55:57.488761 758173 storage/queue.go:1033 [n3,replicate,s3,r71/2:/Table/76/{1/5-2}] no removable replicas from range that needs a removal: [1:0, 2*:17]
I190626 00:55:57.555609 758275 storage/replica_command.go:933 [n2,replicate,s2,r126/3:/Table/76/1/{4-5}] change replicas (REMOVE_REPLICA (n1,s1):2): existing descriptor r126:/Table/76/1/{4-5} [(n1,s1):2, (n2,s2):3, next=4, gen=55]
I190626 00:55:57.631867 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:55:57.632751 758188 storage/replica_command.go:933 [n3,replicate,s3,r71/2:/Table/76/{1/5-2}] change replicas (REMOVE_REPLICA (n1,s1):1): existing descriptor r71:/Table/76/{1/5-2} [(n1,s1):1, (n3,s3):2, next=3, gen=55]
I190626 00:55:57.782780 758275 storage/replica_raft.go:395 [n2,s2,r126/3:/Table/76/1/{4-5}] proposing REMOVE_REPLICA((n1,s1):2): updated=[(n2,s2):3] next=4
I190626 00:55:57.852635 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a < 4
I190626 00:55:57.859479 758290 storage/store.go:2522 [n1,replicaGC,s1,r126/2:/Table/76/1/{4-5}] removing replica r126/2
I190626 00:55:57.863274 477690 storage/queue.go:525 [n2,s2,r9/3:/Table/1{3-4}] rate limited in MaybeAdd (merge): context canceled
I190626 00:55:57.870980 758290 storage/replica_destroy.go:146 [n1,replicaGC,s1,r126/2:/Table/76/1/{4-5}] removed 6 (0+6) keys in 10ms [clear=10ms commit=0ms]
I190626 00:55:57.888741 758188 storage/replica_raft.go:395 [n3,s3,r71/2:/Table/76/{1/5-2}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n3,s3):2] next=3
I190626 00:55:57.897475 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a >= 4 AND a < 5
I190626 00:55:58.004855 733624 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col range partitioning - MAXVALUE" WHERE a > 5
I190626 00:55:58.010550 758686 storage/store.go:2522 [n1,replicaGC,s1,r71/1:/Table/76/{1/5-2}] removing replica r71/1
I190626 00:55:58.012133 758686 storage/replica_destroy.go:146 [n1,replicaGC,s1,r71/1:/Table/76/{1/5-2}] removed 7 (0+7) keys in 1ms [clear=0ms commit=0ms]
TestRepartitioning/single_col_list_partitioning/single_col_list_partitioning_-_DEFAULT
...ies=0ms commit=5ms]
I190626 00:53:35.913974 558823 storage/replica_command.go:933 [n1,replicate,s1,r57/2:/Table/64/1/{5-6}] change replicas (ADD_REPLICA (n3,s3):3): existing descriptor r57:/Table/64/1/{5-6} [(n1,s1):2, next=3, gen=29]
I190626 00:53:36.236932 558823 storage/replica_raft.go:395 [n1,s1,r57/2:/Table/64/1/{5-6}] proposing ADD_REPLICA((n3,s3):3): updated=[(n1,s1):2 (n3,s3):3] next=4
E190626 00:53:36.255387 558823 storage/queue.go:1033 [n1,replicate,s1,r57/2:/Table/64/1/{5-6}] no removable replicas from range that needs a removal: [2*:21, 3:0]
E190626 00:53:36.257141 559323 storage/queue.go:1033 [n1,replicate,s1,r57/2:/Table/64/1/{5-6}] no removable replicas from range that needs a removal: [2*:21, 3:0]
I190626 00:53:36.391289 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "set_zone_config", target: 64, info: {Target:data."single col list partitioning - DEFAULT".pd Config: Options:constraints = '[+n1]' User:root}
I190626 00:53:36.399409 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
I190626 00:53:36.616866 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
E190626 00:53:36.721450 559862 storage/queue.go:1033 [n1,replicate,s1,r57/2:/Table/64/1/{5-6}] no removable replicas from range that needs a removal: [2*:21, 3:0]
I190626 00:53:36.744156 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a > 5
I190626 00:53:36.848552 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
I190626 00:53:36.896170 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
I190626 00:53:36.979781 560159 storage/replica_command.go:933 [n2,replicate,s2,r56/4:/Table/64/1/{4-5}] change replicas (REMOVE_REPLICA (n3,s3):3): existing descriptor r56:/Table/64/1/{4-5} [(n3,s3):3, (n2,s2):4, next=5, gen=28]
I190626 00:53:37.022781 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 5
I190626 00:53:37.140440 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 5
I190626 00:53:37.346507 560159 storage/replica_raft.go:395 [n2,s2,r56/4:/Table/64/1/{4-5}] proposing REMOVE_REPLICA((n3,s3):3): updated=[(n2,s2):4] next=5
I190626 00:53:37.417089 560626 storage/replica_command.go:933 [n3,replicate,s3,r57/3:/Table/64/1/{5-6}] change replicas (REMOVE_REPLICA (n1,s1):2): existing descriptor r57:/Table/64/1/{5-6} [(n1,s1):2, (n3,s3):3, next=4, gen=29]
I190626 00:53:37.526467 560915 storage/store.go:2522 [n3,replicaGC,s3,r56/3:/Table/64/1/{4-5}] removing replica r56/3
I190626 00:53:37.538935 560915 storage/replica_destroy.go:146 [n3,replicaGC,s3,r56/3:/Table/64/1/{4-5}] removed 6 (0+6) keys in 12ms [clear=11ms commit=0ms]
I190626 00:53:37.565811 560626 storage/replica_raft.go:395 [n3,s3,r57/3:/Table/64/1/{5-6}] proposing REMOVE_REPLICA((n1,s1):2): updated=[(n3,s3):3] next=4
I190626 00:53:37.583931 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a > 5
I190626 00:53:37.662845 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a < 4
I190626 00:53:37.705979 538840 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "single col list partitioning - DEFAULT" WHERE a = 4
I190626 00:53:37.708655 561034 storage/store.go:2522 [n1,replicaGC,s1,r57/2:/Table/64/1/{5-6}] removing replica r57/2
I190626 00:53:37.710373 561034 storage/replica_destroy.go:146 [n1,replicaGC,s1,r57/2:/Table/64/1/{5-6}] removed 6 (0+6) keys in 1ms [clear=0ms commit=0ms]
TestRepartitioning/multi_col_range_partitioning_-_MAXVALUE_MAXVALUE/multi_col_range_partitioning_-_MAXVALUE
...c004b5f5e0, 0x1)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/split_queue.go:113 +0x111
github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).maybeAdd(0xc0053dbb80, 0x517e660, 0xc0029528a0, 0x51c2740, 0xc0040e8100, 0x15ab99ab7b644438, 0x0)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:600 +0x2a5
github.com/cockroachdb/cockroach/pkg/storage.baseQueueHelper.MaybeAdd(0xc0053dbb80, 0x517e660, 0xc0029528a0, 0x51c2740, 0xc0040e8100, 0x15ab99ab7b644438, 0xc000000000)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:493 +0x73
github.com/cockroachdb/cockroach/pkg/storage.(*Store).systemGossipUpdate.func2.1(0x517e660, 0xc0029528a0, 0x5146560, 0xc0053dbb80)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:1704 +0x86
github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).Async.func1(0x517e660, 0xc0029528a0)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:523 +0x66
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunLimitedAsyncTask.func1(0xc005950e60, 0x517e660, 0xc0029528a0, 0xc001306380, 0x15, 0xc0062f4c00, 0x0, 0x0, 0xc0041b34c0)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:381 +0x11e
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunLimitedAsyncTask
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:375 +0x2a9
goroutine 477798 [runnable]:
sync.runtime_nanotime(0xc004f48030)
/usr/local/go/src/runtime/sema.go:612 +0x3a
sync.(*Mutex).Lock(0xc004f48030)
/usr/local/go/src/sync/mutex.go:132 +0x2c2
github.com/cockroachdb/cockroach/pkg/util/syncutil.(*Mutex).Lock(0xc004f48030)
/go/src/github.com/cockroachdb/cockroach/pkg/util/syncutil/mutex_sync_race.go:29 +0x3b
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).runPrelude(0xc004f48000, 0xc007661400, 0xd, 0x0)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:387 +0x4d
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunLimitedAsyncTask(0xc004f48000, 0x517e660, 0xc0042c9800, 0xc007661400, 0xd, 0xc001251d40, 0x0, 0xc00662c940, 0x1, 0xc007661400)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:368 +0x1e5
github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).Async(0xc0053da9a0, 0x517e660, 0xc0042c9800, 0xc007661400, 0xd, 0xff1e00, 0xc008013da0)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:521 +0x269
github.com/cockroachdb/cockroach/pkg/storage.(*baseQueue).MaybeAddAsync(0xc0053da9a0, 0x517e660, 0xc0042c9800, 0x51c2740, 0xc007e1a000, 0x15ab99abb123d57f, 0xc000000000)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/queue.go:533 +0x101
github.com/cockroachdb/cockroach/pkg/storage.(*replicaScanner).waitAndProcess(0xc00449bad0, 0x517e660, 0xc0042c9800, 0xc004f48000, 0x32c98422, 0xed4a4ba01, 0x0, 0xc007e1a000, 0x39c2a50)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scanner.go:231 +0x41c
github.com/cockroachdb/cockroach/pkg/storage.(*replicaScanner).scanLoop.func1.1(0xc007e1a000, 0x70)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scanner.go:279 +0x13c
github.com/cockroachdb/cockroach/pkg/storage.(*storeReplicaVisitor).Visit(0xc003ea46c0, 0xc006fe4900)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/store.go:355 +0x312
github.com/cockroachdb/cockroach/pkg/storage.(*replicaScanner).scanLoop.func1(0x517e660, 0xc0042c9800)
/go/src/github.com/cockroachdb/cockroach/pkg/storage/scanner.go:277 +0x38b
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1(0xc0041ddc80, 0xc004f48000, 0xc005339b80)
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:196 +0x160
created by github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker
/go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:189 +0xc4
I190626 00:46:19.595385 1 rand.go:83 Random seed: 3831374970585004264
testing: warning: no tests to run
I190626 00:46:32.442434 1 rand.go:83 Random seed: -1986580733633045560
TestRepartitioning/unpartitioned/unpartitioned
--- FAIL: testrace/TestRepartitioning/unpartitioned/unpartitioned (0.000s)
Test ended in panic.
------- Stdout: -------
I190626 00:52:46.319298 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "drop_database", target: 52, info: {DatabaseName:data Statement:DROP DATABASE IF EXISTS data User:root DroppedSchemaObjects:[]}
I190626 00:52:46.570355 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "create_database", target: 53, info: {DatabaseName:data Statement:CREATE DATABASE data User:root}
I190626 00:52:46.979411 477182 sql/event_log.go:130 [n1,client=127.0.0.1:49654,user=root] Event: "create_table", target: 54, info: {TableName:data.public.unpartitioned Statement:CREATE TABLE unpartitioned (a INT8 PRIMARY KEY) User:root}
I190626 00:52:47.163220 492837 storage/replica_command.go:259 [n1,split,s1,r20/1:/{Table/24-Max}] initiating a split of this range at key /Table/54 [r21] (zone config)
TestRepartitioning/multi_col_list_partitioning_-_DEFAULT/multi_col_list_partitioning
...rage/replica_raft.go:395 [n3,s3,r40/2:/Table/70/1/5/{6-7}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n3,s3):2] next=3
E190626 00:54:42.393123 653829 storage/queue.go:1033 [n3,replicate,s3,r87/2:/Table/70/1/5/{7-8}] no removable replicas from range that needs a removal: [2*:28, 3:0]
I190626 00:54:42.424365 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 6
I190626 00:54:42.563841 653899 storage/store.go:2522 [n1,replicaGC,s1,r40/1:/Table/70/1/5/{6-7}] removing replica r40/1
I190626 00:54:42.572861 653899 storage/replica_destroy.go:146 [n1,replicaGC,s1,r40/1:/Table/70/1/5/{6-7}] removed 6 (0+6) keys in 7ms [clear=7ms commit=0ms]
I190626 00:54:42.592318 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 7
I190626 00:54:42.732362 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) < (3, 4)
I190626 00:54:42.854756 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 3 AND b = 4
I190626 00:54:42.905628 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) > (3, 4) AND (a, b) < (5, 6)
I190626 00:54:42.967956 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 6
I190626 00:54:43.055997 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 7
I190626 00:54:43.136218 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) < (3, 4)
I190626 00:54:43.184911 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 3 AND b = 4
I190626 00:54:43.258627 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) > (3, 4) AND (a, b) < (5, 6)
I190626 00:54:43.373374 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 6
I190626 00:54:43.434708 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 7
I190626 00:54:43.519801 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) < (3, 4)
I190626 00:54:43.565984 477827 server/status/runtime.go:498 [n2] runtime stats: 1.6 GiB RSS, 681 goroutines, 91 MiB/78 MiB/204 MiB GO alloc/idle/total, 124 MiB/172 MiB CGO alloc/total, 2332.5 CGO/sec, 199.8/24.8 %(u/s)time, 0.2 %gc (5x), 3.0 MiB/3.0 MiB (r/w)net
I190626 00:54:43.568277 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 3 AND b = 4
I190626 00:54:43.636169 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) > (3, 4) AND (a, b) < (5, 6)
I190626 00:54:43.691541 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 6
I190626 00:54:43.700723 655613 storage/replica_command.go:933 [n1,replicate,s1,r87/3:/Table/70/1/5/{7-8}] change replicas (REMOVE_REPLICA (n3,s3):2): existing descriptor r87:/Table/70/1/5/{7-8} [(n3,s3):2, (n1,s1):3, next=4, gen=40]
I190626 00:54:43.752032 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE a = 5 AND b = 7
I190626 00:54:43.784944 621163 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning" WHERE (a, b) > (5, 7)
I190626 00:54:43.796310 477761 storage/queue.go:525 [n2,s2,r9/3:/Table/1{3-4}] rate limited in MaybeAdd (merge): context canceled
TestRepartitioning/multi_col_list_partitioning_-_DEFAULT_DEFAULT/multi_col_list_partitioning_-_DEFAULT
...query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:55:41.149723 731727 storage/store.go:2522 [n3,replicaGC,s3,r96/2:/Table/74/1/5/{8-9}] removing replica r96/2
I190626 00:55:41.151557 731727 storage/replica_destroy.go:146 [n3,replicaGC,s3,r96/2:/Table/74/1/5/{8-9}] removed 7 (0+7) keys in 1ms [clear=1ms commit=0ms]
I190626 00:55:41.181267 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 8
I190626 00:55:41.227181 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b > 8
I190626 00:55:41.272489 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) > (3, 4) AND a < 5
I190626 00:55:41.311489 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:55:41.350117 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:55:41.389885 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b > 8
I190626 00:55:41.424284 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) > (3, 4) AND a < 5
I190626 00:55:41.516434 732522 storage/replica_command.go:933 [n2,replicate,s2,r111/4:/Table/74/1/5{-/7}] change replicas (REMOVE_REPLICA (n1,s1):3): existing descriptor r111:/Table/74/1/5{-/7} [(n1,s1):3, (n2,s2):4, next=5, gen=44]
I190626 00:55:41.552052 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b < 7
I190626 00:55:41.644746 732522 storage/replica_raft.go:395 [n2,s2,r111/4:/Table/74/1/5{-/7}] proposing REMOVE_REPLICA((n1,s1):3): updated=[(n2,s2):4] next=5
I190626 00:55:41.689785 732829 storage/replica_command.go:933 [n2,replicate,s2,r97/3:/Table/74/1/{5/9-6}] change replicas (REMOVE_REPLICA (n1,s1):2): existing descriptor r97:/Table/74/1/{5/9-6} [(n1,s1):2, (n2,s2):3, next=4, gen=46]
I190626 00:55:41.715216 732800 storage/store.go:2522 [n1,replicaGC,s1,r111/3:/Table/74/1/5{-/7}] removing replica r111/3
I190626 00:55:41.717078 732800 storage/replica_destroy.go:146 [n1,replicaGC,s1,r111/3:/Table/74/1/5{-/7}] removed 7 (0+7) keys in 1ms [clear=0ms commit=0ms]
I190626 00:55:41.779184 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 7
I190626 00:55:41.819601 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b = 8
I190626 00:55:41.889973 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 5 AND b > 8
I190626 00:55:41.907418 732829 storage/replica_raft.go:395 [n2,s2,r97/3:/Table/74/1/{5/9-6}] proposing REMOVE_REPLICA((n1,s1):2): updated=[(n2,s2):3] next=4
I190626 00:55:42.023619 733323 storage/store.go:2522 [n1,replicaGC,s1,r97/2:/Table/74/1/{5/9-6}] removing replica r97/2
I190626 00:55:42.025478 733323 storage/replica_destroy.go:146 [n1,replicaGC,s1,r97/2:/Table/74/1/{5/9-6}] removed 6 (0+6) keys in 1ms [clear=0ms commit=0ms]
I190626 00:55:42.041563 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a > 5
I190626 00:55:42.107576 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE (a, b) < (3, 4)
I190626 00:55:42.149322 697689 ccl/partitionccl/partition_test.go:206 query: SELECT count(*) FROM "multi col list partitioning - DEFAULT" WHERE a = 3 AND b = 4
Please assign, take a look and update the issue accordingly.