From 5e0c8bbf28e830c8a81bc81eee3633c0a176c30d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Mart=C3=AD?= Date: Sat, 6 Feb 2021 17:58:18 +0000 Subject: [PATCH] peering: add logs before many-second waits This test takes a full minute to run, and I was honestly thinking my run of "go test -v" had simply hung, as I saw no output and no apparent resource usage. The least we can do is print a few log messages before the potentially long waits, to hint that we're still making progress. Each of these "Eventually" and "Never" calls ends up blocking the test for a few seconds at a time. --- peering/peering_test.go | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/peering/peering_test.go b/peering/peering_test.go index 3bfdd9d946e..a6ce1332bde 100644 --- a/peering/peering_test.go +++ b/peering/peering_test.go @@ -57,11 +57,13 @@ func TestPeeringService(t *testing.T) { require.NoError(t, ps1.Start()) // We should eventually connect. + t.Logf("waiting for h1 to connect to h2") require.Eventually(t, func() bool { return h1.Network().Connectedness(h2.ID()) == network.Connected }, 30*time.Second, 10*time.Millisecond) - // Now explicitly connect to p3. + // Now explicitly connect to h3. + t.Logf("waiting for h1's connection to h3 to work") require.NoError(t, h1.Connect(ctx, peer.AddrInfo{ID: h3.ID(), Addrs: h3.Addrs()})) require.Eventually(t, func() bool { return h1.Network().Connectedness(h2.ID()) == network.Connected @@ -72,7 +74,8 @@ func TestPeeringService(t *testing.T) { // force a disconnect h1.ConnManager().TrimOpenConns(ctx) - // Should disconnect from p3. + // Should disconnect from h3. + t.Logf("waiting for h1's connection to h3 to disconnect") require.Eventually(t, func() bool { return h1.Network().Connectedness(h3.ID()) != network.Connected }, 5*time.Second, 10*time.Millisecond) @@ -88,6 +91,7 @@ func TestPeeringService(t *testing.T) { h2.ConnManager().TrimOpenConns(ctx) // All conns to peer should eventually close. + t.Logf("waiting for all connections to close") for _, c := range conns { require.Eventually(t, func() bool { s, err := c.NewStream(context.Background()) @@ -110,11 +114,13 @@ func TestPeeringService(t *testing.T) { h1.ConnManager().TrimOpenConns(ctx) // Should disconnect + t.Logf("waiting for h1 to disconnect from h2") require.Eventually(t, func() bool { return h1.Network().Connectedness(h2.ID()) != network.Connected }, 5*time.Second, 10*time.Millisecond) // Should never reconnect. + t.Logf("ensuring h1 is not connected to h2 again") require.Never(t, func() bool { return h1.Network().Connectedness(h2.ID()) == network.Connected }, 20*time.Second, 1*time.Second) @@ -122,6 +128,7 @@ func TestPeeringService(t *testing.T) { // Until added back ps1.AddPeer(peer.AddrInfo{ID: h2.ID(), Addrs: h2.Addrs()}) ps1.AddPeer(peer.AddrInfo{ID: h3.ID(), Addrs: h3.Addrs()}) + t.Logf("wait for h1 to connect to h2 and h3 again") require.Eventually(t, func() bool { return h1.Network().Connectedness(h2.ID()) == network.Connected }, 30*time.Second, 1*time.Second)