teamcity: failed test: TestDistSQLDrainingHosts

[cockroach-teamcity]

The following tests appear to have failed on master (testrace): TestDistSQLDrainingHosts

You may want to check for open issues.

#957642:

TestDistSQLDrainingHosts
...sary migrations have run
I181010 23:15:34.485427 13323 server/server.go:1587  [n2] serving sql connections
I181010 23:15:34.505691 13875 server/server_update.go:67  [n2] no need to upgrade, cluster already at the newest version
I181010 23:15:34.506661 13877 sql/event_log.go:126  [n2] Event: "node_join", target: 2, info: {Descriptor:{NodeID:2 Address:{NetworkField:tcp AddressField:127.0.0.1:35775} Attrs: Locality: ServerVersion:2.1 BuildTag:v2.2.0-alpha.00000000-1546-g8e1a821 StartedAt:1539213334475555525 LocalityAddress:[]} ClusterID:21a6738a-d52b-476d-800e-30c4456f3710 StartedAt:1539213334475555525 LastUp:1539213334475555525}
I181010 23:15:34.510114 13759 sql/event_log.go:126  [n1,client=127.0.0.1:46668,user=root] Event: "create_database", target: 52, info: {DatabaseName:test Statement:CREATE DATABASE IF NOT EXISTS test User:root}
I181010 23:15:34.514570 13759 sql/event_log.go:126  [n1,client=127.0.0.1:46668,user=root] Event: "create_table", target: 53, info: {TableName:test.public.nums Statement:CREATE TABLE test.public.nums (num INT) User:root}
I181010 23:15:34.536304 13759 storage/replica_command.go:298  [n1,s1,r1/1:/M{in-ax}] initiating a split of this range at key /Table/53/1/1 [r2]
I181010 23:15:34.554306 13759 storage/store_snapshot.go:615  [n1,s1,r2/1:/{Table/53/1/1-Max}] sending preemptive snapshot 9247b79e at applied index 11
I181010 23:15:34.554546 13759 storage/store_snapshot.go:657  [n1,s1,r2/1:/{Table/53/1/1-Max}] streamed snapshot to (n2,s2):?: kv pairs: 8, log entries: 1, rate-limit: 2.0 MiB/sec, 1ms
I181010 23:15:34.555038 13997 storage/replica_raftstorage.go:803  [n2,s2,r2/?:{-}] applying preemptive snapshot at index 11 (id=9247b79e, encoded size=380, 1 rocksdb batches, 1 log entries)
I181010 23:15:34.555384 13997 storage/replica_raftstorage.go:809  [n2,s2,r2/?:/{Table/53/1/1-Max}] applied preemptive snapshot in 0ms [clear=0ms batch=0ms entries=0ms commit=0ms]
I181010 23:15:34.556240 13759 storage/replica_command.go:812  [n1,s1,r2/1:/{Table/53/1/1-Max}] change replicas (ADD_REPLICA (n2,s2):2): read existing descriptor r2:/{Table/53/1/1-Max} [(n1,s1):1, next=2, gen=0]
I181010 23:15:34.560034 13759 storage/replica.go:3899  [n1,s1,r2/1:/{Table/53/1/1-Max}] proposing ADD_REPLICA((n2,s2):2): updated=[(n1,s1):1 (n2,s2):2] next=3
I181010 23:15:34.563109 13855 storage/replica_proposal.go:211  [n2,s2,r2/2:/{Table/53/1/1-Max}] new range lease repl=(n2,s2):2 seq=3 start=1539213334.560390701,0 epo=1 pro=1539213334.560392897,0 following repl=(n1,s1):1 seq=2 start=1539213334.339436732,0 exp=1539213343.339629423,0 pro=1539213334.339650808,0
I181010 23:15:34.564447 14013 storage/replica_command.go:812  [n2,s2,r2/2:/{Table/53/1/1-Max}] change replicas (REMOVE_REPLICA (n1,s1):1): read existing descriptor r2:/{Table/53/1/1-Max} [(n1,s1):1, (n2,s2):2, next=3, gen=0]
I181010 23:15:34.577124 14013 storage/replica.go:3899  [n2,s2,r2/2:/{Table/53/1/1-Max}] proposing REMOVE_REPLICA((n1,s1):1): updated=[(n2,s2):2] next=3
I181010 23:15:34.578719 14077 storage/store.go:2744  [n1,replicaGC,s1,r2/1:/{Table/53/1/1-Max}] removing replica r2/1
I181010 23:15:34.578936 14077 storage/replica.go:878  [n1,replicaGC,s1,r2/1:/{Table/53/1/1-Max}] removed 9 (2+7) keys in 0ms [clear=0ms commit=0ms]
I181010 23:15:34.630347 14029 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] closedts-subscription
1      [async] closedts-rangefeed-subscriber
I181010 23:15:34.630614 14028 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] closedts-rangefeed-subscriber
W181010 23:15:34.630787 14060 storage/raft_transport.go:583  [n1] while processing outgoing Raft queue to node 2: rpc error: code = Unavailable desc = transport is closing:
W181010 23:15:34.632089 14009 storage/raft_transport.go:583  [n2] while processing outgoing Raft queue to node 1: rpc error: code = Canceled desc = context canceled:
I181010 23:15:34.632910 14029 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] closedts-subscription



TestDistSQLDrainingHosts
...cH_vdgaEodYTSGjTn7uef3qCNooTGWNFsQncGCQQM6gIVOgtYa6cfhopb5BzBhUuvGuG-cMCkMI4giucgcEAVv5dcA1SoU0nQEDhU5Wh351Q1Ut6WepfW2BQeadeEyNRshbBsa701LrZIkgeMtuF7-UJWEpnaFpMvS-Zrt0u19nH5vJ06grGXWdFF4bUkioBvvzNp5mMUyz2b3tV-l2suTjYeaDMPz2xvldG_9DfPaP87s2fsW1RtsYbfGi-eubZ92LoCoxPJ81ngp8J1P0mnDMeq4fKLQu3PJwWOlw1QU8h3kUTgYwv4STKPwcN8-j8CIOL_4VO28ffgMAAP__nC9YuA==]]
got:[[https://cockroachdb.github.io/distsqlplan/decode.html#eJyUkEFL9DAQhu_fr_h4TwqBbfeYk-JpL63UFQ8SJDZDKLSZMklAWfrfpc1BV1jR47yT533CnBDYUWMnitDPqGEUZuGeYmRZo_Lg4N6gK4UhzDmtsVHoWQj6hDSkkaBxtK8jdWQdya6CgqNkh3GrnWWYrLzfhDxFKLQ56f8NB4JZFDinz9KYrCfoelG_F996L-RtYtnV59679rE5vnTt08PV9UXX_i-ujuLMIdKZ51JztRgFcp7KISNn6eleuN80ZWw3bgscxVS2dRkOoazWD36F6x_h_TfYLP8-AgAA__-zG6EE]]
I181010 23:20:12.235908 13865 sql/distsql_physical_planner_test.go:513  SucceedsSoon: 
expected:[[https://cockroachdb.github.io/distsqlplan/decode.html#eJyskT1rwzAQhvf-inJTCoJETrpoSumUoXbJBx2KCap1GEMsmZMELcH_vdgaEodYTSGjTn7uef3qCNooTGWNFsQncGCQQM6gIVOgtYa6cfhopb5BzBhUuvGuG-cMCkMI4giucgcEAVv5dcA1SoU0nQEDhU5Wh351Q1Ut6WepfW2BQeadeEyNRshbBsa701LrZIkgeMtuF7-UJWEpnaFpMvS-Zrt0u19nH5vJ06grGXWdFF4bUkioBvvzNp5mMUyz2b3tV-l2suTjYeaDMPz2xvldG_9DfPaP87s2fsW1RtsYbfGi-eubZ92LoCoxPJ81ngp8J1P0mnDMeq4fKLQu3PJwWOlw1QU8h3kUTgYwv4STKPwcN8-j8CIOL_4VO28ffgMAAP__nC9YuA==]]
got:[[https://cockroachdb.github.io/distsqlplan/decode.html#eJyUkEFL9DAQhu_fr_h4TwqBbfeYk-JpL63UFQ8SJDZDKLSZMklAWfrfpc1BV1jR47yT533CnBDYUWMnitDPqGEUZuGeYmRZo_Lg4N6gK4UhzDmtsVHoWQj6hDSkkaBxtK8jdWQdya6CgqNkh3GrnWWYrLzfhDxFKLQ56f8NB4JZFDinz9KYrCfoelG_F996L-RtYtnV59679rE5vnTt08PV9UXX_i-ujuLMIdKZ51JztRgFcp7KISNn6eleuN80ZWw3bgscxVS2dRkOoazWD36F6x_h_TfYLP8-AgAA__-zG6EE]]
I181010 23:20:13.244508 13865 sql/distsql_physical_planner_test.go:513  SucceedsSoon: 
expected:[[https://cockroachdb.github.io/distsqlplan/decode.html#eJyskT1rwzAQhvf-inJTCoJETrpoSumUoXbJBx2KCap1GEMsmZMELcH_vdgaEodYTSGjTn7uef3qCNooTGWNFsQncGCQQM6gIVOgtYa6cfhopb5BzBhUuvGuG-cMCkMI4giucgcEAVv5dcA1SoU0nQEDhU5Wh351Q1Ut6WepfW2BQeadeEyNRshbBsa701LrZIkgeMtuF7-UJWEpnaFpMvS-Zrt0u19nH5vJ06grGXWdFF4bUkioBvvzNp5mMUyz2b3tV-l2suTjYeaDMPz2xvldG_9DfPaP87s2fsW1RtsYbfGi-eubZ92LoCoxPJ81ngp8J1P0mnDMeq4fKLQu3PJwWOlw1QU8h3kUTgYwv4STKPwcN8-j8CIOL_4VO28ffgMAAP__nC9YuA==]]
got:[[https://cockroachdb.github.io/distsqlplan/decode.html#eJyUkEFL9DAQhu_fr_h4TwqBbfeYk-JpL63UFQ8SJDZDKLSZMklAWfrfpc1BV1jR47yT533CnBDYUWMnitDPqGEUZuGeYmRZo_Lg4N6gK4UhzDmtsVHoWQj6hDSkkaBxtK8jdWQdya6CgqNkh3GrnWWYrLzfhDxFKLQ56f8NB4JZFDinz9KYrCfoelG_F996L-RtYtnV59679rE5vnTt08PV9UXX_i-ujuLMIdKZ51JztRgFcp7KISNn6eleuN80ZWw3bgscxVS2dRkOoazWD36F6x_h_TfYLP8-AgAA__-zG6EE]]
I181010 23:20:14.245933 14743 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] closedts-subscription
1      [async] closedts-rangefeed-subscriber
I181010 23:20:14.246985 14742 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
1      [async] closedts-subscription
1      [async] closedts-rangefeed-subscriber
W181010 23:20:14.256709 14428 storage/raft_transport.go:583  [n2] while processing outgoing Raft queue to node 1: rpc error: code = Canceled desc = context canceled:
W181010 23:20:14.257643 14270 gossip/gossip.go:1496  [n2] no incoming or outgoing connections
W181010 23:20:14.256773 14478 storage/raft_transport.go:583  [n1] while processing outgoing Raft queue to node 2: rpc error: code = Canceled desc = grpc: the client connection is closing:
I181010 23:20:14.261308 14742 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
1      [async] closedts-subscription
I181010 23:20:14.262297 14742 util/stop/stopper.go:537  quiescing; tasks left:
1      [async] transport racer
I181010 23:20:14.353316 14504 rpc/nodedialer/nodedialer.go:91  [ct-client] unable to connect to n2: context canceled
I181010 23:20:14.416667 14757 rpc/nodedialer/nodedialer.go:91  [ct-client] unable to connect to n1: context canceled
I181010 23:20:14.712610 13937 kv/transport_race.go:113  transport race promotion: ran 77 iterations on up to 497 requests

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

[jordanlewis]

Dupe of #31235.