Merge pull request #1279 from wpaulino/itest-flakes

test: fix multiple integration test flakes
This commit is contained in:
Olaoluwa Osuntokun 2018-05-25 19:25:36 -07:00 committed by GitHub
commit b401cb6401
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 126 additions and 112 deletions

@ -4009,38 +4009,23 @@ func copyFile(dest, src string) error {
return d.Close()
}
// waitForTxInMempool polls until finding one transaction in the provided
// miner's mempool. An error is returned if *one* transaction isn't found within
// the given timeout.
func waitForTxInMempool(miner *rpcclient.Client,
timeout time.Duration) (*chainhash.Hash, error) {
var txid *chainhash.Hash
breakTimeout := time.After(timeout)
ticker := time.NewTicker(50 * time.Millisecond)
defer ticker.Stop()
poll:
for {
select {
case <-breakTimeout:
return nil, errors.New("no tx found in mempool")
case <-ticker.C:
mempool, err := miner.GetRawMempool()
txs, err := waitForNTxsInMempool(miner, 1, timeout)
if err != nil {
return nil, err
}
if len(mempool) == 0 {
continue
}
txid = mempool[0]
break poll
}
}
return txid, nil
return txs[0], err
}
// waitForNTxsInMempool polls until finding the desired number of transactions
// in the provided miner's mempool. An error is returned if the this number is
// not met after the given timeout.
// in the provided miner's mempool. An error is returned if this number is not
// met after the given timeout.
func waitForNTxsInMempool(miner *rpcclient.Client, n int,
timeout time.Duration) ([]*chainhash.Hash, error) {
@ -4054,7 +4039,7 @@ func waitForNTxsInMempool(miner *rpcclient.Client, n int,
select {
case <-breakTimeout:
return nil, fmt.Errorf("wanted %v, found %v txs "+
"in mempool", n, len(mempool))
"in mempool: %v", n, len(mempool), mempool)
case <-ticker.C:
mempool, err = miner.GetRawMempool()
if err != nil {
@ -5706,15 +5691,17 @@ func testGraphTopologyNotifications(net *lntest.NetworkHarness, t *harnessTest)
// announced to the network and reported in the network graph.
func testNodeAnnouncement(net *lntest.NetworkHarness, t *harnessTest) {
ctxb := context.Background()
aliceUpdates, quit := subscribeGraphNotifications(t, ctxb, net.Alice)
defer close(quit)
ipAddresses := map[string]bool{
"192.168.1.1:8333": true,
"[2001:db8:85a3:8d3:1319:8a2e:370:7348]:8337": true,
advertisedAddrs := []string{
"192.168.1.1:8333",
"[2001:db8:85a3:8d3:1319:8a2e:370:7348]:8337",
}
var lndArgs []string
for address := range ipAddresses {
lndArgs = append(lndArgs, "--externalip="+address)
for _, addr := range advertisedAddrs {
lndArgs = append(lndArgs, "--externalip="+addr)
}
dave, err := net.NewNode("Dave", lndArgs)
@ -5734,42 +5721,48 @@ func testNodeAnnouncement(net *lntest.NetworkHarness, t *harnessTest) {
ctxt, t, net, net.Bob, dave, 1000000, 0, false,
)
// When Alice now connects with Dave, Alice will get his node announcement.
// When Alice now connects with Dave, Alice will get his node
// announcement.
if err := net.ConnectNodes(ctxb, net.Alice, dave); err != nil {
t.Fatalf("unable to connect bob to carol: %v", err)
}
time.Sleep(time.Second * 1)
req := &lnrpc.ChannelGraphRequest{}
chanGraph, err := net.Alice.DescribeGraph(ctxb, req)
if err != nil {
t.Fatalf("unable to query for alice's routing table: %v", err)
assertAddrs := func(addrsFound []string, targetAddrs ...string) {
addrs := make(map[string]struct{}, len(addrsFound))
for _, addr := range addrsFound {
addrs[addr] = struct{}{}
}
for _, node := range chanGraph.Nodes {
if node.PubKey == dave.PubKeyStr {
for _, address := range node.Addresses {
addrStr := address.String()
for _, addr := range targetAddrs {
if _, ok := addrs[addr]; !ok {
t.Fatalf("address %v not found in node "+
"announcement", addr)
}
}
}
// parse the IP address from the string
// representation of the TCPAddr
parts := strings.Split(addrStr, "\"")
if ipAddresses[parts[3]] {
delete(ipAddresses, parts[3])
} else {
if !strings.HasPrefix(parts[3],
"127.0.0.1:") {
t.Fatalf("unexpected IP: %v",
parts[3])
waitForAddrsInUpdate := func(graphUpdates <-chan *lnrpc.GraphTopologyUpdate,
nodePubKey string, targetAddrs ...string) {
for {
select {
case graphUpdate := <-graphUpdates:
for _, update := range graphUpdate.NodeUpdates {
if update.IdentityKey == nodePubKey {
assertAddrs(
update.Addresses,
targetAddrs...,
)
return
}
}
case <-time.After(20 * time.Second):
t.Fatalf("did not receive node ann update")
}
}
}
}
}
if len(ipAddresses) != 0 {
t.Fatalf("expected IP addresses not in channel "+
"graph: %v", ipAddresses)
}
waitForAddrsInUpdate(aliceUpdates, dave.PubKeyStr, advertisedAddrs...)
// Close the channel between Bob and Dave.
ctxt, _ = context.WithTimeout(ctxb, timeout)
@ -6464,6 +6457,7 @@ func testMultiHopHtlcLocalTimeout(net *lntest.NetworkHarness, t *harnessTest) {
dustHtlcAmt = btcutil.Amount(100)
htlcAmt = btcutil.Amount(30000)
finalCltvDelta = 40
csvDelay = 4
)
alicePayStream, err := net.Alice.SendPayment(ctxb)
if err != nil {
@ -6553,15 +6547,20 @@ func testMultiHopHtlcLocalTimeout(net *lntest.NetworkHarness, t *harnessTest) {
t.Fatalf("htlc mismatch: %v", predErr)
}
// TODO(roasbeef): need to fix utxn so it can accept incubation for
// timeout that has already past
//
// * remove after solved
time.Sleep(time.Second * 5)
// We'll mine csvDelay blocks in order to generate the sweep transaction
// of Bob's funding output.
if _, err := net.Miner.Node.Generate(csvDelay); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
_, err = waitForTxInMempool(net.Miner.Node, 10*time.Second)
if err != nil {
t.Fatalf("unable to find bob's funding output sweep tx: %v", err)
}
// We'll now mine the remaining blocks to cause the HTLC itself to
// timeout.
if _, err := net.Miner.Node.Generate(defaultBroadcastDelta); err != nil {
if _, err := net.Miner.Node.Generate(defaultBroadcastDelta - csvDelay); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
@ -6626,7 +6625,7 @@ func testMultiHopHtlcLocalTimeout(net *lntest.NetworkHarness, t *harnessTest) {
}
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
if err != nil {
t.Fatalf("unable to find bob's sweeping transaction")
t.Fatalf("unable to find bob's sweeping transaction: %v", err)
}
// Next, we'll mine a final block that should confirm the second-layer
@ -6854,7 +6853,7 @@ func testMultiHopReceiverChainClaim(net *lntest.NetworkHarness, t *harnessTest)
// We should have a new transaction in the mempool.
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
if err != nil {
t.Fatalf("unable to find bob's sweeping transaction")
t.Fatalf("unable to find bob's sweeping transaction: %v", err)
}
// Finally, if we mine an additional block to confirm these two sweep
@ -6912,6 +6911,7 @@ func testMultiHopLocalForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
// to Carol. As Carol is in hodl mode, she won't settle this HTLC which
// opens up the base for out tests.
const (
csvDelay = 4
finalCltvDelta = 40
htlcAmt = btcutil.Amount(30000)
)
@ -6986,9 +6986,20 @@ func testMultiHopLocalForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
t.Fatalf(predErr.Error())
}
// We'll mine csvDelay blocks in order to generate the sweep transaction
// of Bob's funding output.
if _, err := net.Miner.Node.Generate(csvDelay); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
_, err = waitForTxInMempool(net.Miner.Node, 10*time.Second)
if err != nil {
t.Fatalf("unable to find bob's funding output sweep tx: %v", err)
}
// We'll now mine enough blocks for the HTLC to expire. After this, Bob
// should hand off the now expired HTLC output to the utxo nursery.
if _, err := net.Miner.Node.Generate(finalCltvDelta); err != nil {
if _, err := net.Miner.Node.Generate(finalCltvDelta - csvDelay - 1); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
@ -7030,16 +7041,15 @@ func testMultiHopLocalForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
// We should also now find a transaction in the mempool, as Bob should
// have broadcast his second layer timeout transaction.
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
timeoutTx, err := waitForTxInMempool(net.Miner.Node, 10*time.Second)
if err != nil {
t.Fatalf("unable to find bob's sweeping transaction")
t.Fatalf("unable to find bob's htlc timeout tx: %v", err)
}
// Next, we'll mine an additional block. This should serve to confirm
// the second layer timeout transaction.
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to generate block: %v", err)
}
block := mineBlocks(t, net, 1)[0]
assertTxInBlock(t, block, timeoutTx)
// With the second layer timeout transaction confirmed, Bob should have
// cancelled backwards the HTLC that carol sent.
@ -7088,19 +7098,21 @@ func testMultiHopLocalForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
}
// We'll now mine 4 additional blocks. This should be enough for Bob's
// CSV timelock to expire, and the sweeping transaction to be
// confirmed.
if _, err := net.Miner.Node.Generate(4); err != nil {
// CSV timelock to expire and the sweeping transaction of the HTLC to be
// broadcast.
if _, err := net.Miner.Node.Generate(csvDelay); err != nil {
t.Fatalf("unable to mine blocks: %v", err)
}
time.Sleep(time.Second * 3)
sweepTx, err := waitForTxInMempool(net.Miner.Node, 10*time.Second)
if err != nil {
t.Fatalf("unable to find bob's htlc sweep tx: %v", err)
}
// We'll then mine a final block which should confirm this second layer
// sweep transaction.
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to mine blocks: %v", err)
}
block = mineBlocks(t, net, 1)[0]
assertTxInBlock(t, block, sweepTx)
// At this point, Bob should no longer show any channels as pending
// close.
@ -7139,7 +7151,7 @@ func testMultiHopLocalForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
// channel, then we properly timeout the HTLC on *their* commitment transaction
// once the timeout has expired. Once we sweep the transaction, we should also
// cancel back the initial HTLC.
func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
func testMultiHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
t *harnessTest) {
timeout := time.Duration(time.Second * 15)
@ -7154,6 +7166,7 @@ func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
// to Carol. As Carol is in hodl mode, she won't settle this HTLC which
// opens up the base for out tests.
const (
csvDelay = 4
finalCltvDelta = 40
htlcAmt = btcutil.Amount(30000)
)
@ -7221,10 +7234,21 @@ func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
t.Fatalf(predErr.Error())
}
// We'll mine csvDelay blocks in order to generate the sweep transaction
// of Bob's funding output.
if _, err := net.Miner.Node.Generate(csvDelay); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
_, err = waitForTxInMempool(net.Miner.Node, 10*time.Second)
if err != nil {
t.Fatalf("unable to find bob's funding output sweep tx: %v", err)
}
// Next, we'll mine enough blocks for the HTLC to expire. At this
// point, Bob should hand off the output to his internal utxo nursery,
// which will broadcast a sweep transaction.
if _, err := net.Miner.Node.Generate(finalCltvDelta - 1); err != nil {
if _, err := net.Miner.Node.Generate(finalCltvDelta - csvDelay - 1); err != nil {
t.Fatalf("unable to generate blocks: %v", err)
}
@ -7267,7 +7291,7 @@ func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
// Bob's sweeping transaction should now be found in the mempool at
// this point.
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
sweepTx, err := waitForTxInMempool(net.Miner.Node, time.Second*10)
if err != nil {
// If Bob's transaction isn't yet in the mempool, then due to
// internal message passing and the low period between blocks
@ -7278,18 +7302,17 @@ func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to generate block: %v", err)
}
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
sweepTx, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
if err != nil {
t.Fatalf("unable to find bob's sweeping "+
"transaction: %v", err)
t.Fatalf("unable to find bob's sweeping transaction: "+
"%v", err)
}
}
// If we mine an additional block, then this should confirm Bob's
// transaction which sweeps the direct HTLC output.
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to generate block: %v", err)
}
block := mineBlocks(t, net, 1)[0]
assertTxInBlock(t, block, sweepTx)
// Now that the sweeping transaction has been confirmed, Bob should
// cancel back that HTLC. As a result, Alice should not know of any
@ -7297,21 +7320,10 @@ func testMultHopRemoteForceCloseOnChainHtlcTimeout(net *lntest.NetworkHarness,
nodes = []*lntest.HarnessNode{net.Alice}
err = lntest.WaitPredicate(func() bool {
return assertNumActiveHtlcs(nodes, 0)
}, time.Second*8)
}, time.Second*15)
if err != nil {
// It may be the case that due to a race, Bob's sweeping
// transaction hasn't yet been confirmed, so we'll mine another
// block to nudge it in. If after this it still Alice will has
// an HTLC, then it's actually a test failure.
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to generate block: %v", err)
}
if err = lntest.WaitPredicate(func() bool {
return assertNumActiveHtlcs(nodes, 0)
}, time.Second*8); err != nil {
t.Fatalf("alice's channel still has active htlc's")
}
}
// Now we'll check Bob's pending channel report. Since this was Carol's
// commitment, he doesn't have to wait for any CSV delays. As a result,
@ -7532,23 +7544,25 @@ func testMultiHopHtlcLocalChainClaim(net *lntest.NetworkHarness, t *harnessTest)
}
assertTxInBlock(t, block, secondLevelHash)
// If we then mine 4 additional blocks, Bob should pull the output
// destined for him.
// If we then mine 4 additional blocks, Bob and Carol should sweep the
// outputs destined for them.
if _, err := net.Miner.Node.Generate(defaultCSV); err != nil {
t.Fatalf("unable to generate block: %v", err)
}
_, err = waitForTxInMempool(net.Miner.Node, time.Second*10)
sweepTxs, err := waitForNTxsInMempool(net.Miner.Node, 2, time.Second*10)
if err != nil {
t.Fatalf("unable to find bob's sweeping transaction")
t.Fatalf("unable to find sweeping transactions: %v", err)
}
// At this point, Bob should detect that he has no pending channels
// anymore, as this just resolved it by the confirmation of the sweep
// transaction we detected above.
if _, err := net.Miner.Node.Generate(1); err != nil {
t.Fatalf("unable to generate block: %v", err)
block = mineBlocks(t, net, 1)[0]
for _, sweepTx := range sweepTxs {
assertTxInBlock(t, block, sweepTx)
}
err = lntest.WaitPredicate(func() bool {
pendingChanResp, err := net.Bob.PendingChannels(
ctxb, pendingChansRequest,
@ -7727,7 +7741,7 @@ func testMultiHopHtlcRemoteChainClaim(net *lntest.NetworkHarness, t *harnessTest
_, err = waitForNTxsInMempool(net.Miner.Node, 1, time.Second*15)
if err != nil {
t.Fatalf("unable to find bob's sweeping transaction")
t.Fatalf("unable to find bob's sweeping transaction: %v", err)
}
// We'll now mine another block, this should confirm the sweep
@ -9338,7 +9352,7 @@ var testsCases = []*testCase{
// bob: outgoing their commit watch and see timeout
// carol: incoming our commit watch and see timeout
name: "test multi-hop remote force close on-chain htlc timeout",
test: testMultHopRemoteForceCloseOnChainHtlcTimeout,
test: testMultiHopRemoteForceCloseOnChainHtlcTimeout,
},
{
// bob: outgoing our commit watch and see, they sweep on chain

@ -998,8 +998,8 @@ func (n *NetworkHarness) WaitForChannelClose(ctx context.Context,
}
}
// AssertChannelExists asserts that an active channel identified by
// channelPoint is known to exist from the point-of-view of node..
// AssertChannelExists asserts that an active channel identified by the
// specified channel point exists from the point-of-view of the node.
func (n *NetworkHarness) AssertChannelExists(ctx context.Context,
node *HarnessNode, chanPoint *wire.OutPoint) error {
@ -1015,7 +1015,7 @@ func (n *NetworkHarness) AssertChannelExists(ctx context.Context,
for _, channel := range resp.Channels {
if channel.ChannelPoint == chanPoint.String() {
return true
return channel.Active
}
}