Merge pull request #4737 from bhandras/itest_clean_state

itest: clean harness state before each icase and better naming for icase logs

.gitignore

@@ -32,8 +32,7 @@ _testmain.go
 /lncli-itest
 
 # Integration test log files
-lntest/itest/output*.log
-lntest/itest/pprof*.log
+lntest/itest/*.log
 lntest/itest/.backendlogs
 lntest/itest/.minerlogs
 lntest/itest/lnd-itest
@@ -73,4 +72,4 @@ profile.tmp
 .vscode
 
 # Coverage test
-coverage.txt
+coverage.txt

lntest/harness.go

@@ -36,6 +36,9 @@ const DefaultCSV = 4
 type NetworkHarness struct {
 	netParams *chaincfg.Params
 
+	// currentTestCase holds the name for the currently run test case.
+	currentTestCase string
+
 	// lndBinary is the full path to the lnd binary that was specifically
 	// compiled with all required itest flags.
 	lndBinary string
@@ -131,10 +134,11 @@ func (f *fakeLogger) Println(args ...interface{})               {}
 // rpc clients capable of communicating with the initial seeder nodes are
 // created. Nodes are initialized with the given extra command line flags, which
 // should be formatted properly - "--arg=value".
-func (n *NetworkHarness) SetUp(lndArgs []string) error {
+func (n *NetworkHarness) SetUp(testCase string, lndArgs []string) error {
 	// Swap out grpc's default logger with out fake logger which drops the
 	// statements on the floor.
 	grpclog.SetLogger(&fakeLogger{})
+	n.currentTestCase = testCase
 
 	// Start the initial seeder nodes within the test network, then connect
 	// their respective RPC clients.
@@ -241,21 +245,23 @@ out:
 	return nil
 }
 
-// TearDownAll tears down all active nodes within the test lightning network.
-func (n *NetworkHarness) TearDownAll() error {
-
+// TearDown tears down all active nodes within the test lightning network.
+func (n *NetworkHarness) TearDown() error {
 	for _, node := range n.activeNodes {
 		if err := n.ShutdownNode(node); err != nil {
 			return err
 		}
 	}
 
+	return nil
+}
+
+// Stop stops the test harness.
+func (n *NetworkHarness) Stop() {
 	close(n.lndErrorChan)
 	close(n.quit)
 
 	n.feeService.stop()
-
-	return nil
 }
 
 // NewNode fully initializes a returns a new HarnessNode bound to the
@@ -358,17 +364,18 @@ func (n *NetworkHarness) RestoreNodeWithSeed(name string, extraArgs []string,
 // wallet with or without a seed. If hasSeed is false, the returned harness node
 // can be used immediately. Otherwise, the node will require an additional
 // initialization phase where the wallet is either created or restored.
-func (n *NetworkHarness) newNode(name string, extraArgs []string,
-	hasSeed bool, password []byte) (*HarnessNode, error) {
+func (n *NetworkHarness) newNode(name string, extraArgs []string, hasSeed bool,
+	password []byte) (*HarnessNode, error) {
 
 	node, err := newNode(NodeConfig{
-		Name:       name,
-		HasSeed:    hasSeed,
-		Password:   password,
-		BackendCfg: n.BackendCfg,
-		NetParams:  n.netParams,
-		ExtraArgs:  extraArgs,
-		FeeURL:     n.feeService.url,
+		Name:              name,
+		LogFilenamePrefix: n.currentTestCase,
+		HasSeed:           hasSeed,
+		Password:          password,
+		BackendCfg:        n.BackendCfg,
+		NetParams:         n.netParams,
+		ExtraArgs:         extraArgs,
+		FeeURL:            n.feeService.url,
 	})
 	if err != nil {
 		return nil, err

lntest/itest/lnd_macaroons_test.go

@@ -22,7 +22,7 @@ import (
 // enabled on the gRPC interface, no requests with missing or invalid
 // macaroons are allowed. Further, the specific access rights (read/write,
 // entity based) and first-party caveats are tested as well.
-func testMacaroonAuthentication(net *lntest.NetworkHarness, t *harnessTest) {
+func testMacaroonAuthentication(net *lntest.NetworkHarness, ht *harnessTest) {
 	var (
 		infoReq    = &lnrpc.GetInfoRequest{}
 		newAddrReq = &lnrpc.NewAddressRequest{
@@ -200,15 +200,13 @@ func testMacaroonAuthentication(net *lntest.NetworkHarness, t *harnessTest) {
 
 	for _, tc := range testCases {
 		tc := tc
-		t.t.Run(tc.name, func(t *testing.T) {
-			t.Parallel()
-
+		ht.t.Run(tc.name, func(tt *testing.T) {
 			ctxt, cancel := context.WithTimeout(
 				context.Background(), defaultTimeout,
 			)
 			defer cancel()
 
-			tc.run(ctxt, t)
+			tc.run(ctxt, tt)
 		})
 	}
 }
@@ -377,9 +375,7 @@ func testBakeMacaroon(net *lntest.NetworkHarness, t *harnessTest) {
 
 	for _, tc := range testCases {
 		tc := tc
-		t.t.Run(tc.name, func(t *testing.T) {
-			t.Parallel()
-
+		t.t.Run(tc.name, func(tt *testing.T) {
 			ctxt, cancel := context.WithTimeout(
 				context.Background(), defaultTimeout,
 			)
@@ -388,11 +384,11 @@ func testBakeMacaroon(net *lntest.NetworkHarness, t *harnessTest) {
 			adminMac, err := testNode.ReadMacaroon(
 				testNode.AdminMacPath(), defaultTimeout,
 			)
-			require.NoError(t, err)
-			cleanup, client := macaroonClient(t, testNode, adminMac)
+			require.NoError(tt, err)
+			cleanup, client := macaroonClient(tt, testNode, adminMac)
 			defer cleanup()
 
-			tc.run(ctxt, t, client)
+			tc.run(ctxt, tt, client)
 		})
 	}
 }

lntest/itest/lnd_test.go

@@ -14232,7 +14232,7 @@ func TestLightningNetworkDaemon(t *testing.T) {
 	if err != nil {
 		ht.Fatalf("unable to create lightning network harness: %v", err)
 	}
-	defer lndHarness.TearDownAll()
+	defer lndHarness.Stop()
 
 	// Spawn a new goroutine to watch for any fatal errors that any of the
 	// running lnd processes encounter. If an error occurs, then the test
@@ -14265,37 +14265,52 @@ func TestLightningNetworkDaemon(t *testing.T) {
 	aliceBobArgs := []string{
 		"--default-remote-max-htlcs=483",
 	}
-	if err = lndHarness.SetUp(aliceBobArgs); err != nil {
-		ht.Fatalf("unable to set up test lightning network: %v", err)
-	}
 
 	// Run the subset of the test cases selected in this tranche.
 	for idx, testCase := range testCases {
 		testCase := testCase
-		logLine := fmt.Sprintf("STARTING ============ %v ============\n",
-			testCase.name)
-
-		err := lndHarness.EnsureConnected(
-			context.Background(), lndHarness.Alice, lndHarness.Bob,
-		)
-		if err != nil {
-			t.Fatalf("unable to connect alice to bob: %v", err)
-		}
-
-		if err := lndHarness.Alice.AddToLog(logLine); err != nil {
-			t.Fatalf("unable to add to log: %v", err)
-		}
-		if err := lndHarness.Bob.AddToLog(logLine); err != nil {
-			t.Fatalf("unable to add to log: %v", err)
-		}
-
-		// Start every test with the default static fee estimate.
-		lndHarness.SetFeeEstimate(12500)
-
 		name := fmt.Sprintf("%02d-of-%d/%s/%s",
 			trancheOffset+uint(idx)+1, len(allTestCases),
 			chainBackend.Name(), testCase.name)
+
 		success := t.Run(name, func(t1 *testing.T) {
+			cleanTestCaseName := strings.ReplaceAll(
+				testCase.name, " ", "_",
+			)
+
+			err = lndHarness.SetUp(cleanTestCaseName, aliceBobArgs)
+			require.NoError(t1,
+				err, "unable to set up test lightning network",
+			)
+			defer func() {
+				require.NoError(t1, lndHarness.TearDown())
+			}()
+
+			err = lndHarness.EnsureConnected(
+				context.Background(), lndHarness.Alice,
+				lndHarness.Bob,
+			)
+			require.NoError(t1,
+				err, "unable to connect alice to bob",
+			)
+
+			logLine := fmt.Sprintf(
+				"STARTING ============ %v ============\n",
+				testCase.name,
+			)
+
+			err = lndHarness.Alice.AddToLog(logLine)
+			require.NoError(t1, err, "unable to add to log")
+
+			err = lndHarness.Bob.AddToLog(logLine)
+			require.NoError(t1, err, "unable to add to log")
+
+			// Start every test with the default static fee estimate.
+			lndHarness.SetFeeEstimate(12500)
+
+			// Create a separate harness test for the testcase to
+			// avoid overwriting the external harness test that is
+			// tied to the parent test.
 			ht := newHarnessTest(t1, lndHarness)
 			ht.RunTestCase(testCase)
 		})

lntest/itest/log_error_whitelist.txt

@@ -49,6 +49,7 @@
 <time> [ERR] DISC: Unable to reply to peer query: set tcp <ip>: use of closed network connection
 <time> [ERR] DISC: Unable to reply to peer query: write tcp <ip>-><ip>: use of closed network connection
 <time> [ERR] DISC: Unable to reply to peer query: write tcp <ip>-><ip>: write: broken pipe
+<time> [ERR] DISC: Unable to reply to peer query: write tcp <ip>-><ip>: write: connection reset by peer
 <time> [ERR] FNDG: received funding error from <hex>: chan_id=<hex>, err=channel too large
 <time> [ERR] FNDG: received funding error from <hex>: chan_id=<hex>, err=chan size of 0.16777216 BTC exceeds maximum chan size of 0.16777215 BTC
 <time> [ERR] FNDG: received funding error from <hex>: chan_id=<hex>, err=chan size of 10.00000001 BTC exceeds maximum chan size of 0.16777215 BTC

lntest/node.go

@@ -153,7 +153,12 @@ type BackendConfig interface {
 }
 
 type NodeConfig struct {
-	Name       string
+	Name string
+
+	// LogFilenamePrefix is is used to prefix node log files. Can be used
+	// to store the current test case for simpler postmortem debugging.
+	LogFilenamePrefix string
+
 	BackendCfg BackendConfig
 	NetParams  *chaincfg.Params
 	BaseDir    string
@@ -493,17 +498,21 @@ func (hn *HarnessNode) start(lndBinary string, lndError chan<- error) error {
 	// log files.
 	if *logOutput {
 		dir := GetLogDir()
-		fileName := fmt.Sprintf("%s/output-%d-%s-%s.log", dir, hn.NodeID,
-			hn.Cfg.Name, hex.EncodeToString(hn.PubKey[:logPubKeyBytes]))
+		fileName := fmt.Sprintf("%s/%d-%s-%s-%s.log", dir, hn.NodeID,
+			hn.Cfg.LogFilenamePrefix, hn.Cfg.Name,
+			hex.EncodeToString(hn.PubKey[:logPubKeyBytes]))
 
-		// If the node's PubKey is not yet initialized, create a temporary
-		// file name. Later, after the PubKey has been initialized, the
-		// file can be moved to its final name with the PubKey included.
+		// If the node's PubKey is not yet initialized, create a
+		// temporary file name. Later, after the PubKey has been
+		// initialized, the file can be moved to its final name with
+		// the PubKey included.
 		if bytes.Equal(hn.PubKey[:4], []byte{0, 0, 0, 0}) {
-			fileName = fmt.Sprintf("%s/output-%d-%s-tmp__.log",
-				dir, hn.NodeID, hn.Cfg.Name)
+			fileName = fmt.Sprintf("%s/%d-%s-%s-tmp__.log", dir,
+				hn.NodeID, hn.Cfg.LogFilenamePrefix,
+				hn.Cfg.Name)
 
-			// Once the node has done its work, the log file can be renamed.
+			// Once the node has done its work, the log file can be
+			// renamed.
 			finalizeLogfile = func() {
 				if hn.logFile != nil {
 					hn.logFile.Close()
@@ -511,8 +520,10 @@ func (hn *HarnessNode) start(lndBinary string, lndError chan<- error) error {
 					pubKeyHex := hex.EncodeToString(
 						hn.PubKey[:logPubKeyBytes],
 					)
-					newFileName := fmt.Sprintf("%s/output"+
-						"-%d-%s-%s.log", dir, hn.NodeID,
+					newFileName := fmt.Sprintf("%s/"+
+						"%d-%s-%s-%s.log",
+						dir, hn.NodeID,
+						hn.Cfg.LogFilenamePrefix,
 						hn.Cfg.Name, pubKeyHex)
 					err := os.Rename(fileName, newFileName)
 					if err != nil {