teamcity: failed test: TestInitialPartitioning #41846

cockroach-teamcity · 2019-10-23T06:10:29Z

The following tests appear to have failed on master (testrace): TestInitialPartitioning/time_table, TestInitialPartitioning/bytes_table, TestInitialPartitioning/date_table, TestInitialPartitioning, TestInitialPartitioning/secondary_index_-_NULL, TestInitialPartitioning/interval_table, TestInitialPartitioning/collatedstring{da}_table, TestInitialPartitioning/inet_table, TestInitialPartitioning/oid_table, TestInitialPartitioning/string_table, TestInitialPartitioning/float_table, TestInitialPartitioning/varbit_table, TestInitialPartitioning/timestamp_table, TestInitialPartitioning/timestamptz_table

You may want to check for open issues.

#1554251:

TestInitialPartitioning/bytes_table
....0.1:37466,user=root] added table 'data.public.bytes_table' to table collection
              [n1,client=127.0.0.1:37466,user=root] query cache hit
              [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/85/1
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
               === SPAN START: table reader ===
            cockroach.processorid: 0
            cockroach.stat.tablereader.bytes.read: 0 B
            cockroach.stat.tablereader.input.rows: 0
            cockroach.stat.tablereader.stalltime: 6.948ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/85/1{-/""}
               === SPAN START: txn coordinator send ===
               === SPAN START: [async] drain ===
               === SPAN START: dist sender send ===
              [n3,txn=90f90d9a] querying next range at /Table/85/1
              [n3,txn=90f90d9a] r236: sending batch 1 Scan to (n3,s3):1
              [n3,txn=90f90d9a] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r236/1:/Table/85/1{-/""}] read-only path
               === SPAN START: flow ===
              [n3,s3,r236/1:/Table/85/1{-/""}] acquire latches
              [n3,s3,r236/1:/Table/85/1{-/""}] waited 66.85µs to acquire latches
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
              [n3,s3,r236/1:/Table/85/1{-/""}] waiting for read lock
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3,s3,r236/1:/Table/85/1{-/""}] 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: 553µs
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:14754] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 935460 [running]:
            runtime/debug.Stack(0xc004f8c900, 0x6722520, 0xc005e841a0)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc00595c900, 0xc004f8c900)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc00595c900)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc00595c900, 0xc00456fdd0)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/secondary_index_-_NULL
...0.0.1:37466,user=root] generating optimizer plan
              [n1,client=127.0.0.1:37466,user=root] added table 'data.public."secondary index - NULL"' to table collection
              [n1,client=127.0.0.1:37466,user=root] query cache hit
              [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/75/2/3
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,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: 23.855ms
              [n1,client=127.0.0.1:37466,user=root] starting scan with limitBatches true
              [n1,client=127.0.0.1:37466,user=root] Scan /Table/75/2/{3-4}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n1,client=127.0.0.1:37466,user=root,txn=4e15bd34] querying next range at /Table/75/2/3
              [n1,client=127.0.0.1:37466,user=root,txn=4e15bd34] r178: sending batch 1 Scan to (n1,s1):1
              [n1,client=127.0.0.1:37466,user=root,txn=4e15bd34] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n1] 1 Scan
              [n1,s1] executing 1 requests
              [n1,s1,r178/1:/Table/75/2/{3-4}] read-only path
              [n1,s1,r178/1:/Table/75/2/{3-4}] read has no clock uncertainty
              [n1,s1,r178/1:/Table/75/2/{3-4}] acquire latches
              [n1,s1,r178/1:/Table/75/2/{3-4}] waited 58.047µs to acquire latches
              [n1,s1,r178/1:/Table/75/2/{3-4}] waiting for read lock
              [n1,s1,r178/1:/Table/75/2/{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: 383µs
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:10094] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 516330 [running]:
            runtime/debug.Stack(0xc004b90450, 0x6722520, 0xc006705f80)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc005617600, 0xc004b90450)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc005617600)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc005617600, 0xc000ef5080)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/timestamptz_table
...ng ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/86/1
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            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: 15.039ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/86/1{-/2999-12-31T23:59:59.999999Z/#}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=e1ae721c] querying next range at /Table/86/1
              [n3,txn=e1ae721c] r241: sending batch 1 Scan to (n3,s3):1
              [n3,txn=e1ae721c] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r241/1:/Table/86/1{-/3000-0…}] read-only path
              [n3,s3,r241/1:/Table/86/1{-/3000-0…}] acquire latches
              [n3,s3,r241/1:/Table/86/1{-/3000-0…}] waited 182.243µs to acquire latches
              [n3,s3,r241/1:/Table/86/1{-/3000-0…}] waiting for read lock
              [n3,s3,r241/1:/Table/86/1{-/3000-0…}] read completed
              [n3] Consumer sent handshake. Consuming flow scheduled: false
               === SPAN START: count rows ===
            cockroach.processorid: 1
            cockroach.stat.aggregator.input.rows: 0
            cockroach.stat.aggregator.mem.max: 0 B
            cockroach.stat.aggregator.stalltime: 665µs
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:15155] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 985110 [running]:
            runtime/debug.Stack(0xc005b1fce0, 0x6722520, 0xc00582a420)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc00419d000, 0xc005b1fce0)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc00419d000)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc00419d000, 0xc004809a40)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/oid_table
...r=root] query cache hit
              [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/87/1/2927754667
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === 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.547ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/87/{1/2927754667-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=92cf45c7] querying next range at /Table/87/1/2927754667
              [n3,txn=92cf45c7] r248: sending batch 1 Scan to (n3,s3):1
              [n3,txn=92cf45c7] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r248/1:/{Table/87/1/2…-Max}] read-only path
              [n3,s3,r248/1:/{Table/87/1/2…-Max}] acquire latches
              [n3,s3,r248/1:/{Table/87/1/2…-Max}] waited 137.785µs to acquire latches
              [n3,s3,r248/1:/{Table/87/1/2…-Max}] waiting for read lock
              [n3,s3,r248/1:/{Table/87/1/2…-Max}] 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: 507µs
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
               === SPAN START: [async] drain ===
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:15568] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 1035800 [running]:
            runtime/debug.Stack(0xc005704150, 0x6722520, 0xc00275b820)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0033f7c00, 0xc005704150)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0033f7c00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0033f7c00, 0xc005dd3290)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/float_table
...  [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/79/1/0.5238724808958248
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: table reader ===
            cockroach.processorid: 0
            cockroach.stat.tablereader.bytes.read: 0 B
            cockroach.stat.tablereader.input.rows: 0
            cockroach.stat.tablereader.stalltime: 20.369ms
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/79/{1/0.5238724808958248-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=2e8ebc1a] querying next range at /Table/79/1/0.5238724808958248
               === SPAN START: [async] drain ===
              [n3,txn=2e8ebc1a] r208: sending batch 1 Scan to (n3,s3):2
              [n3,txn=2e8ebc1a] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] Consumer sent handshake. Consuming flow scheduled: false
               === SPAN START: flow ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r208/2:/Table/79/{1/0.523…-2}] read-only path
              [n3,s3,r208/2:/Table/79/{1/0.523…-2}] acquire latches
              [n3,s3,r208/2:/Table/79/{1/0.523…-2}] waited 97.272µs to acquire latches
              [n3,s3,r208/2:/Table/79/{1/0.523…-2}] waiting for read lock
              [n3,s3,r208/2:/Table/79/{1/0.523…-2}] 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: 18.535ms
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:12138] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 653280 [running]:
            runtime/debug.Stack(0xc005704660, 0x6722520, 0xc005d6d4c0)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0062b2600, 0xc005704660)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0062b2600)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0062b2600, 0xc005c2d140)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/interval_table
...            [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/83/1/-81 years -11 mons -855 days -43:00:19.805326
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === 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.433ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/83/{1/-81 years -11 mons -855 days -43:00:19.805326-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=153759d5] querying next range at /Table/83/1/-81 years -11 mons -855 days -43:00:19.805326
              [n3,txn=153759d5] r228: sending batch 1 Scan to (n3,s3):1
              [n3,txn=153759d5] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r228/1:/{Table/83/1/-…-Max}] read-only path
              [n3,s3,r228/1:/{Table/83/1/-…-Max}] acquire latches
              [n3,s3,r228/1:/{Table/83/1/-…-Max}] waited 94.657µs to acquire latches
              [n3,s3,r228/1:/{Table/83/1/-…-Max}] waiting for read lock
              [n3,s3,r228/1:/{Table/83/1/-…-Max}] read completed
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.3 KiB
            cockroach.streamid: 1
               === SPAN START: count rows ===
            cockroach.processorid: 1
            cockroach.stat.aggregator.input.rows: 0
            cockroach.stat.aggregator.mem.max: 0 B
            cockroach.stat.aggregator.stalltime: 658µs
               === SPAN START: [async] drain ===
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:13946] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 842038 [running]:
            runtime/debug.Stack(0xc0038a8f00, 0x6722520, 0xc004438a00)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc003c02600, 0xc0038a8f00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc003c02600)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc003c02600, 0xc0044b9f80)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/timestamp_table
...=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/82/1/1970-01-08T13:18:51.000823Z
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
               === 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.858ms
               === SPAN START: [async] drain ===
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/82/{1/1970-01-08T13:18:51.000823Z-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=c82e94df] querying next range at /Table/82/1/1970-01-08T13:18:51.000823Z
              [n3,txn=c82e94df] r223: sending batch 1 Scan to (n3,s3):1
              [n3,txn=c82e94df] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r223/1:/Table/82/{1/1970-…-2}] read-only path
              [n3,s3,r223/1:/Table/82/{1/1970-…-2}] acquire latches
              [n3,s3,r223/1:/Table/82/{1/1970-…-2}] waited 100.388µs to acquire latches
              [n3,s3,r223/1:/Table/82/{1/1970-…-2}] waiting for read lock
              [n3,s3,r223/1:/Table/82/{1/1970-…-2}] 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: 410µs
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: false
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:13503] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 792741 [running]:
            runtime/debug.Stack(0xc006b1e6c0, 0x6722520, 0xc005687aa0)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc004521c00, 0xc006b1e6c0)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc004521c00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc004521c00, 0xc0048084e0)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/inet_table
...ockroach.roachpb.Internal/Batch ===
              [n2] 1 Scan
              [n2,s2] executing 1 requests
              [n2,s2,r1/3:/{Min-System/NodeL…}] read-only path
              [n2,s2,r1/3:/{Min-System/NodeL…}] acquire latches
              [n2,s2,r1/3:/{Min-System/NodeL…}] operation accepts inconsistent results
              [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:37466,user=root] looked up range descriptor: r258:/Table/89/{1/"\x00\x1c\xe1l\xf7\xaf"/PrefixEnd-2} [(n3,s3):1, next=2, gen=234]
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: table reader ===
            cockroach.processorid: 0
            cockroach.stat.tablereader.bytes.read: 0 B
            cockroach.stat.tablereader.input.rows: 0
            cockroach.stat.tablereader.stalltime: 16.287ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/89/{1/"\x00\x1c\xe1l\xf7\xb0"-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=66c63daf] querying next range at /Table/89/1/"\x00\x1c\xe1l\xf7\xb0"
              [n3,txn=66c63daf] r258: sending batch 1 Scan to (n3,s3):1
              [n3,txn=66c63daf] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r258/1:/Table/89/{1/"\x00…-2}] read-only path
              [n3,s3,r258/1:/Table/89/{1/"\x00…-2}] acquire latches
              [n3,s3,r258/1:/Table/89/{1/"\x00…-2}] waited 83.289µs to acquire latches
              [n3,s3,r258/1:/Table/89/{1/"\x00…-2}] waiting for read lock
              [n3,s3,r258/1:/Table/89/{1/"\x00…-2}] read completed
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
               === SPAN START: count rows ===
            cockroach.processorid: 1
            cockroach.stat.aggregator.input.rows: 0
            cockroach.stat.aggregator.mem.max: 0 B
            cockroach.stat.aggregator.stalltime: 628µs
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
               === SPAN START: [async] drain ===
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:16478] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 1129912 [running]:
            runtime/debug.Stack(0xc00412c1e0, 0x6722520, 0xc005b4dd60)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc001e9dc00, 0xc00412c1e0)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc001e9dc00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc001e9dc00, 0xc00533a540)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/time_table
...ing ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/90/1/48888221938
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            cockroach.streamid: 1
               === SPAN START: table reader ===
            cockroach.processorid: 0
            cockroach.stat.tablereader.bytes.read: 0 B
            cockroach.stat.tablereader.input.rows: 0
            cockroach.stat.tablereader.stalltime: 19.87ms
               === SPAN START: [async] drain ===
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/90/{1/48888221938-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=5bc98ff5] querying next range at /Table/90/1/48888221938
              [n3,txn=5bc98ff5] r262: sending batch 1 Scan to (n3,s3):1
              [n3,txn=5bc98ff5] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r262/1:/{Table/90/1/4…-Max}] read-only path
              [n3,s3,r262/1:/{Table/90/1/4…-Max}] acquire latches
              [n3,s3,r262/1:/{Table/90/1/4…-Max}] waited 100.895µs to acquire latches
              [n3,s3,r262/1:/{Table/90/1/4…-Max}] waiting for read lock
              [n3] Consumer sent handshake. Consuming flow scheduled: false
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n3,s3,r262/1:/{Table/90/1/4…-Max}] 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: 1.058ms
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:16861] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 1181907 [running]:
            runtime/debug.Stack(0xc0063324e0, 0x6722520, 0xc004ac2680)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0033f7d00, 0xc0063324e0)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0033f7d00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0033f7d00, 0xc004ea1350)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/varbit_table
...bility
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/91/1/B01100101100010101101100011010010100011011101100111110101001101110001001
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.3 KiB
            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.702ms
              [n3] starting scan with limitBatches false
              [n3] Scan /Table/91/1/B01100101100010101101100011010010100011011101100111110101001101110001001{-/#}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=378d7122] querying next range at /Table/91/1/B01100101100010101101100011010010100011011101100111110101001101110001001
              [n3,txn=378d7122] r265: sending batch 1 Scan to (n3,s3):1
              [n3,txn=378d7122] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r265/1:/{Table/91-Max}] read-only path
              [n3,s3,r265/1:/{Table/91-Max}] acquire latches
              [n3,s3,r265/1:/{Table/91-Max}] waited 110.081µs to acquire latches
              [n3,s3,r265/1:/{Table/91-Max}] waiting for read lock
              [n3,s3,r265/1:/{Table/91-Max}] 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: 506µs
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:17244] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 1227644 [running]:
            runtime/debug.Stack(0xc002735860, 0x6722520, 0xc0030d3d40)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0040f6000, 0xc002735860)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0040f6000)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0040f6000, 0xc005aade30)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/date_table
...:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/81/1/7511
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            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: 43.191ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/81/{1/7511-2}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=9b611314] querying next range at /Table/81/1/7511
              [n3,txn=9b611314] r218: sending batch 1 Scan to (n3,s3):1
              [n3,txn=9b611314] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
              [n3,s3] executing 1 requests
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3,s3,r218/1:/Table/81/{1/7511-2}] read-only path
              [n3] Consumer sent handshake. Consuming flow scheduled: false
              [n3,s3,r218/1:/Table/81/{1/7511-2}] acquire latches
              [n3,s3,r218/1:/Table/81/{1/7511-2}] waited 131.422µs to acquire latches
              [n3,s3,r218/1:/Table/81/{1/7511-2}] waiting for read lock
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n3,s3,r218/1:/Table/81/{1/7511-2}] 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: 565µs
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:13006] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 745676 [running]:
            runtime/debug.Stack(0xc003e8a000, 0x6722520, 0xc005476020)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0036d2500, 0xc003e8a000)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0036d2500)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0036d2500, 0xc004a9be00)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning/collatedstring{da}_table
...le/91/2-Max}] acquire latches
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n3,s3,r269/1:/Table/9{1/2-2}] waited 304.531282ms to acquire latches
              [n3,s3,r269/1:/Table/9{1/2-2}] waiting for read lock
              [n3,s3,r269/1:/Table/9{1/2-2}] replica.Send got error: key range /Table/92/1-/Table/92/1/"\x8f\x11L\x89s\xf5\x8e\u007f\u038d[\x88\x90wH\x92\xc0\t\x91鎄X\x9e\x00\x00\x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00\x00\x02\x02\x02\x02\x02\x02\x02\x02" outside of bounds of range /Table/91/2-/Table/92
              [n3] *roachpb.RangeKeyMismatchError
              [n3,txn=12164d06] reply error [txn: 12164d06], Scan [/Table/92/1,/Table/92/1/"\x8f\x11L\x89s\xf5\x8e\u007f\u038d[\x88\x90wH\x92\xc0\t\x91鎄X\x9e\x00\x00\x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00\x00\x02\x02\x02\x02\x02\x02\x02\x02"): key range /Table/92/1-/Table/92/1/"\x8f\x11L\x89s\xf5\x8e\u007f\u038d[\x88\x90wH\x92\xc0\t\x91鎄X\x9e\x00\x00\x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00\x00\x02\x02\x02\x02\x02\x02\x02\x02" outside of bounds of range /Table/91/2-/Table/92
              [n3,txn=12164d06] evicting cached range descriptor with 2 replacements
              [n3,txn=12164d06] likely split; resending batch to span: key range /Table/92/1-/Table/92/1/"\x8f\x11L\x89s\xf5\x8e\u007f\u038d[\x88\x90wH\x92\xc0\t\x91鎄X\x9e\x00\x00\x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00 \x00\x00\x02\x02\x02\x02\x02\x02\x02\x02" outside of bounds of range /Table/91/2-/Table/92
              [n3,txn=12164d06] querying next range at /Table/92/1
              [n3,txn=12164d06] r270: sending batch 1 Scan to (n3,s3):1
              [n3,txn=12164d06] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r270/1:/{Table/92-Max}] read-only path
              [n3,s3,r270/1:/{Table/92-Max}] acquire latches
              [n3,s3,r270/1:/{Table/92-Max}] waited 103.187µs to acquire latches
              [n3,s3,r270/1:/{Table/92-Max}] waiting for read lock
              [n3,s3,r270/1:/{Table/92-Max}] 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: 12.143ms
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:17633] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 1274141 [running]:
            runtime/debug.Stack(0xc0035401e0, 0x6722520, 0xc00118b3a0)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc0040f7600, 0xc0035401e0)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc0040f7600)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc0040f7600, 0xc002d726c0)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b



TestInitialPartitioning
...23 05:16:00.400828 3145 storage/store_snapshot.go:978  [n1,replicate,s1,r10/1:/Table/1{4-5}] sending LEARNER snapshot 7162fd55 at applied index 17
I191023 05:16:00.401707 31755 storage/raft_snapshot_queue.go:125  [n1,raftsnapshot,s1,r10/1:/Table/1{4-5}] skipping snapshot; replica is likely a learner in the process of being added: (n3,s3):2LEARNER
I191023 05:16:00.406105 3145 storage/store_snapshot.go:1021  [n1,replicate,s1,r10/1:/Table/1{4-5}] streamed snapshot to (n3,s3):2LEARNER: kv pairs: 6, log entries: 0, rate-limit: 8.0 MiB/sec, 0.07s
I191023 05:16:00.409348 31784 storage/replica_raftstorage.go:794  [n3,s3,r10/2:{-}] applying LEARNER snapshot [id=7162fd55 index=17]
I191023 05:16:00.443461 31784 storage/replica_raftstorage.go:815  [n3,s3,r10/2:/Table/1{4-5}] applied LEARNER snapshot [total=34ms ingestion=4@12ms id=7162fd55 index=17]
I191023 05:16:00.452789 3145 storage/replica_command.go:1586  [n1,replicate,s1,r10/1:/Table/1{4-5}] change replicas (add [(n3,s3):2] remove []): existing descriptor r10:/Table/1{4-5} [(n1,s1):1, (n3,s3):2LEARNER, next=3, gen=1]
I191023 05:16:00.531699 3145 storage/replica_raft.go:291  [n1,s1,r10/1:/Table/1{4-5}] proposing ADD_REPLICA[(n3,s3):2]: after=[(n1,s1):1 (n3,s3):2] next=3
I191023 05:16:00.575782 3145 storage/replica_command.go:1586  [n1,replicate,s1,r10/1:/Table/1{4-5}] change replicas (add [(n2,s2):3LEARNER] remove []): existing descriptor r10:/Table/1{4-5} [(n1,s1):1, (n3,s3):2, next=3, gen=2]
I191023 05:16:00.711347 3145 storage/replica_raft.go:291  [n1,s1,r10/1:/Table/1{4-5}] proposing ADD_REPLICA[(n2,s2):3LEARNER]: after=[(n1,s1):1 (n3,s3):2 (n2,s2):3LEARNER] next=4
I191023 05:16:00.788717 3145 storage/store_snapshot.go:978  [n1,replicate,s1,r10/1:/Table/1{4-5}] sending LEARNER snapshot f09c0b78 at applied index 22
I191023 05:16:00.798538 3145 storage/store_snapshot.go:1021  [n1,replicate,s1,r10/1:/Table/1{4-5}] streamed snapshot to (n2,s2):3LEARNER: kv pairs: 10, log entries: 0, rate-limit: 8.0 MiB/sec, 0.03s
I191023 05:16:00.801451 32413 storage/replica_raftstorage.go:794  [n2,s2,r10/3:{-}] applying LEARNER snapshot [id=f09c0b78 index=22]
I191023 05:16:00.810238 32404 storage/raft_snapshot_queue.go:125  [n1,raftsnapshot,s1,r10/1:/Table/1{4-5}] skipping snapshot; replica is likely a learner in the process of being added: (n2,s2):3LEARNER
I191023 05:16:00.847356 32413 storage/replica_raftstorage.go:815  [n2,s2,r10/3:/Table/1{4-5}] applied LEARNER snapshot [total=37ms ingestion=4@34ms id=f09c0b78 index=22]
I191023 05:16:00.875068 3145 storage/replica_command.go:1586  [n1,replicate,s1,r10/1:/Table/1{4-5}] change replicas (add [(n2,s2):3] remove []): existing descriptor r10:/Table/1{4-5} [(n1,s1):1, (n3,s3):2, (n2,s2):3LEARNER, next=4, gen=3]
I191023 05:16:01.064590 3145 storage/replica_raft.go:291  [n1,s1,r10/1:/Table/1{4-5}] proposing ADD_REPLICA[(n2,s2):3]: after=[(n1,s1):1 (n3,s3):2 (n2,s2):3] next=4
I191023 05:16:01.092516 3145 storage/queue.go:1134  [n1,replicate] purgatory is now empty
I191023 05:16:01.143499 2688 testutils/testcluster/testcluster.go:747  WaitForFullReplication took: 18.729822945s
I191023 05:16:01.445180 4706 sql/event_log.go:132  [n1,client=127.0.0.1:37466,user=root] Event: "create_database", target: 52, info: {DatabaseName:data Statement:CREATE DATABASE data User:root}
I191023 05:16:01.455402 7622 server/status/runtime.go:498  [n3] runtime stats: 675 MiB RSS, 747 goroutines, 49 MiB/63 MiB/136 MiB GO alloc/idle/total, 90 MiB/133 MiB CGO alloc/total, 2481.2 CGO/sec, 170.3/17.7 %(u/s)time, 1.4 %gc (8x), 2.4 MiB/2.4 MiB (r/w)net
I191023 05:16:01.660340 4706 sql/event_log.go:132  [n1,client=127.0.0.1:37466,user=root] Event: "set_cluster_setting", target: 0, info: {SettingName:server.declined_reservation_timeout Value:00:00:00 User:root}
I191023 05:16:01.863373 4706 sql/event_log.go:132  [n1,client=127.0.0.1:37466,user=root] Event: "set_cluster_setting", target: 0, info: {SettingName:server.failed_reservation_timeout Value:00:00:00 User:root}



TestInitialPartitioning/string_table
...
              [n1,client=127.0.0.1:37466,user=root] query cache hit
              [n1,client=127.0.0.1:37466,user=root] planning ends
              [n1,client=127.0.0.1:37466,user=root] checking distributability
              [n1,client=127.0.0.1:37466,user=root] will distribute plan: true
              [n1,client=127.0.0.1:37466,user=root] execution starts: distributed engine
               === SPAN START: consuming rows ===
              [n1,client=127.0.0.1:37466,user=root] creating DistSQL plan with isLocal=false
              [n1,client=127.0.0.1:37466,user=root] querying next range at /Table/84/1
              [n1,client=127.0.0.1:37466,user=root] running DistSQL plan
               === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow ===
               === SPAN START: outbox ===
            cockroach.stat.outbox.bytes_sent: 2.2 KiB
            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: 24.221ms
              [n3] starting scan with limitBatches true
              [n3] Scan /Table/84/1{-/"\""}
               === SPAN START: txn coordinator send ===
               === SPAN START: dist sender send ===
              [n3,txn=52bafd01] querying next range at /Table/84/1
               === SPAN START: flow ===
              [n1,client=127.0.0.1:37466,user=root] starting (0 processors, 0 startables)
               === SPAN START: noop ===
            cockroach.processorid: 2
              [n3] Consumer sent handshake. Consuming flow scheduled: true
              [n3,txn=52bafd01] r231: sending batch 1 Scan to (n3,s3):1
              [n3,txn=52bafd01] sending request to local client
               === SPAN START: /cockroach.roachpb.Internal/Batch ===
              [n3] 1 Scan
              [n3,s3] executing 1 requests
              [n3,s3,r231/1:/{Table/84/1-Max}] read-only path
              [n3,s3,r231/1:/{Table/84/1-Max}] acquire latches
              [n3,s3,r231/1:/{Table/84/1-Max}] waited 82.362µs to acquire latches
              [n3,s3,r231/1:/{Table/84/1-Max}] waiting for read lock
              [n3,s3,r231/1:/{Table/84/1-Max}] 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: 490µs
              [n1,client=127.0.0.1:37466,user=root] execution ends
              [n1,client=127.0.0.1:37466,user=root] rows affected: 1
              [n1,client=127.0.0.1:37466,user=root] AutoCommit. err: <nil>
              [n1,client=127.0.0.1:37466,user=root] releasing 1 tables
               === SPAN START: exec stmt ===
              [n1,client=127.0.0.1:37466,user=root] [NoTxn pos:14329] executing ExecStmt: SET TRACING = off
              [n1,client=127.0.0.1:37466,user=root] executing: SET TRACING = off in state: NoTxn
            goroutine 890256 [running]:
            runtime/debug.Stack(0xc003f17f20, 0x6722520, 0xc0035c5820)
            	/usr/local/go/src/runtime/debug/stack.go:24 +0xab
            github.com/cockroachdb/cockroach/pkg/testutils.SucceedsSoon(0x6816820, 0xc001081b00, 0xc003f17f20)
            	/go/src/github.com/cockroachdb/cockroach/pkg/testutils/soon.go:37 +0x87
            github.com/cockroachdb/cockroach/pkg/ccl/partitionccl.TestInitialPartitioning.func1(0xc001081b00)
            	/go/src/github.com/cockroachdb/cockroach/pkg/ccl/partitionccl/partition_test.go:1196 +0x23a
            testing.tRunner(0xc001081b00, 0xc003613ec0)
            	/usr/local/go/src/testing/testing.go:865 +0x164
            created by testing.(*T).Run
            	/usr/local/go/src/testing/testing.go:916 +0x65b

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

The text was updated successfully, but these errors were encountered:

This reverts commit 0b0c71f, reversing changes made to 9b36103. Reverting "config,sqlbase: move computation of splits for SQL tables to sqlbase". It seems to have caused TestInitialPartitioning and TestRepartitioning to timeout often when run under testrace on TC (only when the build runs on the master branch and these tests are run in conjunction with all the other packages). I don't know what's wrong yet. Fixes cockroachdb#41812 Fixes cockroachdb#41821 Fixes cockroachdb#41825 Fixes cockroachdb#41831 Fixes cockroachdb#41835 Fixes cockroachdb#41843 Fixes cockroachdb#41846 Fixes cockroachdb#41850 Fixes cockroachdb#41862 Fixes cockroachdb#41874 Fixes cockroachdb#41879 Fixes cockroachdb#41652 Fixes cockroachdb#41813 Fixes cockroachdb#41822 Fixes cockroachdb#41826 Fixes cockroachdb#41832 Fixes cockroachdb#41836 Fixes cockroachdb#41844 Fixes cockroachdb#41847 Fixes cockroachdb#41851 Fixes cockroachdb#41868 Fixes cockroachdb#41875 Release note: None

cockroach-teamcity added C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Oct 23, 2019

cockroach-teamcity added this to the 19.2 milestone Oct 23, 2019

andreimatei mentioned this issue Oct 23, 2019

all: Revert #39722 #41880

Merged

andreimatei closed this as completed in #41880 Oct 24, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

teamcity: failed test: TestInitialPartitioning #41846

teamcity: failed test: TestInitialPartitioning #41846

cockroach-teamcity commented Oct 23, 2019

teamcity: failed test: TestInitialPartitioning #41846

teamcity: failed test: TestInitialPartitioning #41846

Comments

cockroach-teamcity commented Oct 23, 2019