diff --git a/docs/release-notes/release-notes-0.14.0.md b/docs/release-notes/release-notes-0.14.0.md index cc3018476..264191a57 100644 --- a/docs/release-notes/release-notes-0.14.0.md +++ b/docs/release-notes/release-notes-0.14.0.md @@ -205,6 +205,8 @@ you. * [Fixed wallet recovery itests on Travis ARM](https://github.com/lightningnetwork/lnd/pull/5688) +* [Integration tests save embedded etcd logs to help debugging flakes](https://github.com/lightningnetwork/lnd/pull/5702) + ## Database * [Ensure single writer for legacy diff --git a/kvdb/backend.go b/kvdb/backend.go index a5307dfa5..9bf210c41 100644 --- a/kvdb/backend.go +++ b/kvdb/backend.go @@ -256,7 +256,7 @@ func GetTestBackend(path, name string) (Backend, func(), error) { } return db, empty, nil } else if TestBackend == EtcdBackendName { - etcdConfig, cancel, err := StartEtcdTestBackend(path, 0, 0) + etcdConfig, cancel, err := StartEtcdTestBackend(path, 0, 0, "") if err != nil { return nil, empty, err } diff --git a/kvdb/etcd/config.go b/kvdb/etcd/config.go index 5ae91c220..8798bcb60 100644 --- a/kvdb/etcd/config.go +++ b/kvdb/etcd/config.go @@ -10,6 +10,8 @@ type Config struct { EmbeddedPeerPort uint16 `long:"embedded_peer_port" description:"Peer port to use for the embedded instance. Note: use for testing only."` + EmbeddedLogFile string `long:"embedded_log_file" description:"Optional log file to use for embedded instance logs. note: use for testing only."` + Host string `long:"host" description:"Etcd database host."` User string `long:"user" description:"Etcd database user."` diff --git a/kvdb/etcd/embed.go b/kvdb/etcd/embed.go index c045e6cb8..a4f969149 100644 --- a/kvdb/etcd/embed.go +++ b/kvdb/etcd/embed.go @@ -60,8 +60,8 @@ func getFreePort() int { // NewEmbeddedEtcdInstance creates an embedded etcd instance for testing, // listening on random open ports. Returns the backend config and a cleanup // func that will stop the etcd instance. -func NewEmbeddedEtcdInstance(path string, clientPort, peerPort uint16) ( - *Config, func(), error) { +func NewEmbeddedEtcdInstance(path string, clientPort, peerPort uint16, + logFile string) (*Config, func(), error) { cfg := embed.NewConfig() cfg.Dir = path @@ -70,7 +70,12 @@ func NewEmbeddedEtcdInstance(path string, clientPort, peerPort uint16) ( cfg.MaxTxnOps = 8192 cfg.MaxRequestBytes = 16384 * 1024 cfg.Logger = "zap" - cfg.LogLevel = "error" + if logFile != "" { + cfg.LogLevel = "info" + cfg.LogOutputs = []string{logFile} + } else { + cfg.LogLevel = "error" + } // Listen on random free ports if no ports were specified. if clientPort == 0 { diff --git a/kvdb/etcd/fixture.go b/kvdb/etcd/fixture.go index 8fcfb9f5c..3a32ba09b 100644 --- a/kvdb/etcd/fixture.go +++ b/kvdb/etcd/fixture.go @@ -34,7 +34,7 @@ type EtcdTestFixture struct { func NewTestEtcdInstance(t *testing.T, path string) (*Config, func()) { t.Helper() - config, cleanup, err := NewEmbeddedEtcdInstance(path, 0, 0) + config, cleanup, err := NewEmbeddedEtcdInstance(path, 0, 0, "") if err != nil { t.Fatalf("error while staring embedded etcd instance: %v", err) } diff --git a/kvdb/kvdb_etcd.go b/kvdb/kvdb_etcd.go index 2b798d88f..0637baf24 100644 --- a/kvdb/kvdb_etcd.go +++ b/kvdb/kvdb_etcd.go @@ -12,10 +12,10 @@ const TestBackend = EtcdBackendName // GetEtcdTestBackend creates an embedded etcd backend for testing // storig the database at the passed path. -func StartEtcdTestBackend(path string, clientPort, peerPort uint16) ( - *etcd.Config, func(), error) { +func StartEtcdTestBackend(path string, clientPort, peerPort uint16, + logFile string) (*etcd.Config, func(), error) { return etcd.NewEmbeddedEtcdInstance( - path, clientPort, peerPort, + path, clientPort, peerPort, logFile, ) } diff --git a/kvdb/kvdb_no_etcd.go b/kvdb/kvdb_no_etcd.go index ec7abf775..588fce37f 100644 --- a/kvdb/kvdb_no_etcd.go +++ b/kvdb/kvdb_no_etcd.go @@ -15,8 +15,8 @@ const TestBackend = BoltBackendName var errEtcdNotAvailable = fmt.Errorf("etcd backend not available") // StartEtcdTestBackend is a stub returning nil, and errEtcdNotAvailable error. -func StartEtcdTestBackend(path string, clientPort, peerPort uint16) ( - *etcd.Config, func(), error) { +func StartEtcdTestBackend(path string, clientPort, peerPort uint16, + logFile string) (*etcd.Config, func(), error) { return nil, func() {}, errEtcdNotAvailable } diff --git a/lncfg/db.go b/lncfg/db.go index 63023c918..aa0dcd602 100644 --- a/lncfg/db.go +++ b/lncfg/db.go @@ -92,7 +92,7 @@ func (db *DB) Init(ctx context.Context, dbPath string) error { if db.Backend == EtcdBackend && db.Etcd.Embedded { cfg, _, err := kvdb.StartEtcdTestBackend( dbPath, db.Etcd.EmbeddedClientPort, - db.Etcd.EmbeddedPeerPort, + db.Etcd.EmbeddedPeerPort, db.Etcd.EmbeddedLogFile, ) if err != nil { return err diff --git a/lntest/itest/lnd_etcd_failover_test.go b/lntest/itest/lnd_etcd_failover_test.go index bf3ca7ec3..14c15ab97 100644 --- a/lntest/itest/lnd_etcd_failover_test.go +++ b/lntest/itest/lnd_etcd_failover_test.go @@ -70,7 +70,7 @@ func testEtcdFailoverCase(net *lntest.NetworkHarness, ht *harnessTest, tmpDir, err := ioutil.TempDir("", "etcd") etcdCfg, cleanup, err := kvdb.StartEtcdTestBackend( tmpDir, uint16(lntest.NextAvailablePort()), - uint16(lntest.NextAvailablePort()), + uint16(lntest.NextAvailablePort()), "", ) if err != nil { ht.Fatalf("Failed to start etcd instance: %v", err) diff --git a/lntest/node.go b/lntest/node.go index 69dc26ad6..1b33d55d1 100644 --- a/lntest/node.go +++ b/lntest/node.go @@ -11,6 +11,7 @@ import ( "net" "os" "os/exec" + "path" "path/filepath" "strings" "sync" @@ -324,6 +325,12 @@ func (cfg NodeConfig) genArgs() []string { NextAvailablePort(), ), ) + args = append( + args, fmt.Sprintf( + "--db.etcd.embedded_log_file=%v", + path.Join(cfg.LogDir, "etcd.log"), + ), + ) } if cfg.FeeURL != "" { @@ -558,6 +565,15 @@ func (hn *HarnessNode) InvoiceMacPath() string { return hn.Cfg.InvoiceMacPath } +// renameFile is a helper to rename (log) files created during integration tests. +func renameFile(fromFileName, toFileName string) { + err := os.Rename(fromFileName, toFileName) + if err != nil { + fmt.Printf("could not rename %s to %s: %v\n", + fromFileName, toFileName, err) + } +} + // Start launches a new process running lnd. Additionally, the PID of the // launched process is saved in order to possibly kill the process forcibly // later. @@ -584,6 +600,30 @@ func (hn *HarnessNode) start(lndBinary string, lndError chan<- error, } } + getFinalizedLogFilePrefix := func() string { + pubKeyHex := hex.EncodeToString( + hn.PubKey[:logPubKeyBytes], + ) + + return fmt.Sprintf("%s/%d-%s-%s-%s", + GetLogDir(), hn.NodeID, + hn.Cfg.LogFilenamePrefix, + hn.Cfg.Name, pubKeyHex) + } + + finalizeEtcdLog := func() { + if hn.Cfg.DbBackend != BackendEtcd { + return + } + + etcdLogFileName := fmt.Sprintf("%s/etcd.log", hn.Cfg.LogDir) + newEtcdLogFileName := fmt.Sprintf("%v-etcd.log", + getFinalizedLogFilePrefix(), + ) + + renameFile(etcdLogFileName, newEtcdLogFileName) + } + // If the logoutput flag is passed, redirect output from the nodes to // log files. if *logOutput { @@ -600,29 +640,19 @@ func (hn *HarnessNode) start(lndBinary string, lndError chan<- error, 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. - finalizeLogfile = func() { - if hn.logFile != nil { - hn.logFile.Close() + // Once the node has done its work, the log file can be + // renamed. + finalizeLogfile = func() { + if hn.logFile != nil { + hn.logFile.Close() - pubKeyHex := hex.EncodeToString( - hn.PubKey[:logPubKeyBytes], - ) - 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 { - fmt.Printf("could not rename "+ - "%s to %s: %v\n", - fileName, newFileName, - err) - } - } + newFileName := fmt.Sprintf("%v.log", + getFinalizedLogFilePrefix(), + ) + + renameFile(fileName, newFileName) } } @@ -666,6 +696,10 @@ func (hn *HarnessNode) start(lndBinary string, lndError chan<- error, // Make sure log file is closed and renamed if necessary. finalizeLogfile() + + // Rename the etcd.log file if the node was running on embedded + // etcd. + finalizeEtcdLog() }() // Write process ID to a file. diff --git a/sample-lnd.conf b/sample-lnd.conf index 61d285e4c..59b7231c8 100644 --- a/sample-lnd.conf +++ b/sample-lnd.conf @@ -1131,6 +1131,10 @@ litecoin.node=ltcd ; If non zero, LND will use this as peer port for the embedded etcd instance. ; db.etcd.embedded_peer_port=1235 +; If set the embedded etcd instance will log to the specified file. Useful when +; testing with embedded etcd. +; db.etcd.embedded_log_file=/path/etcd.log + [cluster]