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 test: TestRepartitioning #38427

Closed
cockroach-teamcity opened this issue Jun 26, 2019 · 1 comment · Fixed by #38418
Closed

teamcity: failed test: TestRepartitioning #38427

cockroach-teamcity opened this issue Jun 26, 2019 · 1 comment · Fixed by #38418
Assignees
@jeffrey-xiao
Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Milestone
19.2

Comments

@cockroach-teamcity
Copy link
Member

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.

#1360369:

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.
@cockroach-teamcity cockroach-teamcity added this to the 19.2 milestone Jun 26, 2019
@cockroach-teamcity cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Jun 26, 2019
@nvanbenschoten
Copy link
Member

The failure was a little tricky to find, but here it is:

panic: runtime error: invalid memory address or nil pointer dereference [recovered]^M
        panic: runtime error: invalid memory address or nil pointer dereference^M
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x316afb7]^M
^M
goroutine 905014 [running]:^M
[01:15:18] :                     [TestRepartitioning/multi_col_range_partitioning_-_MAXVALUE_MAXVALUE/multi_col_range_partitioning_-_MAXVALUE] [Test Output]^M
github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).Recover(0xc004680fa0, 0x517e660, 0xc008622b70)^M
        /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:181 +0x155^M
panic(0x412a640, 0x72cead0)^M
        /usr/local/go/src/runtime/panic.go:522 +0x1b5^M
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).AdminMerge.func1(0xc009b2db90, 0xc00459d800, 0xc0019d9800)^M
        /go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_command.go:534 +0x2e7^M
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).AdminMerge(0xc00481ac00, 0x517e620, 0xc00459d800, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)^M
        /go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_command.go:666 +0x479^M

This will be fixed by #38418. Leaving it open until then.

@jeffrey-xiao jeffrey-xiao mentioned this issue Jun 26, 2019
Merged
craig bot pushed a commit that referenced this issue Jun 26, 2019
@danhhz @jeffrey-xiao @rohany
Merge #38211 #38418 #38435
56c18d8 
38211: changefeedccl: remove deprecated poller r=tbg a=danhhz

We switched the default to push-based rangefeeds in 19.1. This removes
the old pull-based poller fallback entirely.

Details of the removal:
- The relevant code is removed
- Several poller-related hacks are removed
- The changefeed.run.push.enabled telemetry metric is removed
- The changefeed.push.enabled cluster setting is removed
- The poller subtest is removed from each changefeedccl test
- The cdc/poller roachtest is skipped on 19.2+
- TestValidations is removed, it's redundant with the much better
  quality TestChangefeedNemeses

Note that the table history still does some polling, but switching this
to RangeFeed will cause an unacceptable increase in the commit-to-emit
latency of rows. This bit of polling will be removed as part of #36289.
This commit also leaves the structure of the changefeed code mostly
unchanged. There is an opportunity for cleanup here, but this also will
wait for after #36289.

Closes #36914

Release note: None

38418: storage: fix null pointer dereference in AdminMerge r=jeffrey-xiao a=jeffrey-xiao

Fixes #38427.

I noticed that `TestRepartitioning` was failing under stress on master with the following error:

```
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x20894f6]

...

        /usr/lib/go-1.12/src/runtime/panic.go:522 +0x1b5
github.com/cockroachdb/cockroach/pkg/storage.(*Replica).AdminMerge.func1(0xc00441e750, 0xc002a83e60, 0xc00020a880)
        /home/cockroach/go/src/github.com/cockroachdb/cockroach/pkg/storage/replica_command.go:536 +0x226

...
```

The logic for retrieving the RHS descriptor before and after #38302 is not the same in the case where `rightDesc` does not exist. This PR changes it so the behavior is consistent.

It seems possible that the following branch can evaluate true, but I might be missing something here.
```go
// Verify that the two ranges are mergeable.
if !bytes.Equal(origLeftDesc.EndKey, rightDesc.StartKey) {
  // Should never happen, but just in case.
  return errors.Errorf("ranges are not adjacent; %s != %s", origLeftDesc.EndKey, rightDesc.StartKey)
}
```


38435: sql: Fixing interleave check for loose index scan r=rohany a=rohany

Fixing the interleave check for the loose index scan while interleave support is in progress.

Co-authored-by: Daniel Harrison <daniel.harrison@gmail.com>
Co-authored-by: Jeffrey Xiao <jeffrey.xiao1998@gmail.com>
Co-authored-by: Rohan Yadav <rohany@alumni.cmu.edu>
@craig craig bot closed this as completed in #38418 Jun 26, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jeffrey-xiao jeffrey-xiao

Labels
C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
19.2
Development

Successfully merging a pull request may close this issue.

storage: fix null pointer dereference in AdminMerge jeffrey-xiao/cockroach
3 participants
@nvanbenschoten @jeffrey-xiao @cockroach-teamcity