diff --git a/tests/framework/e2e/cluster_proxy.go b/tests/framework/e2e/cluster_proxy.go index f090d1c6e7d..f69673dbbe4 100644 --- a/tests/framework/e2e/cluster_proxy.go +++ b/tests/framework/e2e/cluster_proxy.go @@ -112,6 +112,14 @@ func (p *proxyEtcdProcess) Logs() LogsExpect { return p.etcdProc.Logs() } +func (p *proxyEtcdProcess) Lines() []string { + return p.etcdProc.Logs().Lines() +} + +func (p *proxyEtcdProcess) LineCount() int { + return p.etcdProc.Logs().LineCount() +} + func (p *proxyEtcdProcess) Kill() error { return p.etcdProc.Kill() } diff --git a/tests/framework/e2e/etcd_process.go b/tests/framework/e2e/etcd_process.go index 38934f861b6..49a7d62b89b 100644 --- a/tests/framework/e2e/etcd_process.go +++ b/tests/framework/e2e/etcd_process.go @@ -40,8 +40,14 @@ var ( EtcdServerReadyLines = []string{"ready to serve client requests"} ) +type LogLines interface { + Lines() []string + LineCount() int +} + // EtcdProcess is a process that serves etcd requests. type EtcdProcess interface { + LogLines EndpointsGRPC() []string EndpointsHTTP() []string EndpointsMetrics() []string @@ -61,9 +67,8 @@ type EtcdProcess interface { } type LogsExpect interface { + LogLines ExpectWithContext(context.Context, string) (string, error) - Lines() []string - LineCount() int } type EtcdServerProcess struct { @@ -72,6 +77,7 @@ type EtcdServerProcess struct { proxy proxy.Server failpoints *BinaryFailpoints donec chan struct{} // closed when Interact() terminates + logs *procLogs } type EtcdServerProcessConfig struct { @@ -108,7 +114,7 @@ func NewEtcdServerProcess(cfg *EtcdServerProcessConfig) (*EtcdServerProcess, err return nil, err } } - ep := &EtcdServerProcess{cfg: cfg, donec: make(chan struct{})} + ep := &EtcdServerProcess{cfg: cfg, donec: make(chan struct{}), logs: &procLogs{}} if cfg.GoFailPort != 0 { ep.failpoints = &BinaryFailpoints{member: ep} } @@ -124,8 +130,8 @@ func (ep *EtcdServerProcess) EndpointsHTTP() []string { } func (ep *EtcdServerProcess) EndpointsMetrics() []string { return []string{ep.cfg.MetricsURL} } -func (epc *EtcdServerProcess) Etcdctl(opts ...config.ClientOption) *EtcdctlV3 { - etcdctl, err := NewEtcdctl(epc.Config().Client, epc.EndpointsGRPC(), opts...) +func (ep *EtcdServerProcess) Etcdctl(opts ...config.ClientOption) *EtcdctlV3 { + etcdctl, err := NewEtcdctl(ep.Config().Client, ep.EndpointsGRPC(), opts...) if err != nil { panic(err) } @@ -177,6 +183,7 @@ func (ep *EtcdServerProcess) Stop() (err error) { return nil } defer func() { + ep.logs.append(ep.proc.Lines()) ep.proc = nil }() @@ -235,6 +242,14 @@ func (ep *EtcdServerProcess) Logs() LogsExpect { return ep.proc } +func (ep *EtcdServerProcess) Lines() []string { + return ep.logs.Lines() +} + +func (ep *EtcdServerProcess) LineCount() int { + return ep.logs.LineCount() +} + func (ep *EtcdServerProcess) Kill() error { ep.cfg.lg.Info("killing server...", zap.String("name", ep.cfg.Name)) return ep.proc.Signal(syscall.SIGKILL) @@ -378,3 +393,20 @@ func GetVersionFromBinary(binaryPath string) (*semver.Version, error) { return nil, fmt.Errorf("could not find version in binary output of %s, lines outputted were %v", binaryPath, lines) } + +type procLogs struct { + procLogs []string +} + +func (m *procLogs) append(lines []string) { + m.procLogs = append(m.procLogs, strings.Repeat("=", 50)+"\n") + m.procLogs = append(m.procLogs, lines...) +} + +func (m *procLogs) Lines() []string { + return m.procLogs +} + +func (m *procLogs) LineCount() int { + return len(m.procLogs) +} diff --git a/tests/robustness/report.go b/tests/robustness/report.go index 4e995acbdb0..acea15d0333 100644 --- a/tests/robustness/report.go +++ b/tests/robustness/report.go @@ -67,6 +67,9 @@ func (r *report) Report(t *testing.T, force bool) { for _, member := range r.clus.Procs { memberDataDir := filepath.Join(path, fmt.Sprintf("server-%s", member.Config().Name)) persistMemberDataDir(t, r.lg, member, memberDataDir) + + logsFile := filepath.Join(path, fmt.Sprintf("server-%s.log", member.Config().Name)) + persistMemberLogs(t, r.lg, member, logsFile) } if r.clientReports != nil { sort.Slice(r.clientReports, func(i, j int) bool { @@ -118,6 +121,14 @@ func persistWatchResponses(t *testing.T, lg *zap.Logger, path string, responses } } +func persistMemberLogs(t *testing.T, lg *zap.Logger, member e2e.EtcdProcess, path string) { + lg.Info("Saving member logs dir", zap.String("member", member.Config().Name), zap.String("path", path)) + err := os.WriteFile(path, []byte(strings.Join(member.Lines(), "")), 0644) + if err != nil { + t.Fatal(err) + } +} + func persistWatchEvents(t *testing.T, lg *zap.Logger, path string, events []traffic.TimedWatchEvent) { lg.Info("Saving watch events", zap.String("path", path)) file, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0755) diff --git a/tests/robustness/validate/operations.go b/tests/robustness/validate/operations.go index 9189af12675..2fce39a8196 100644 --- a/tests/robustness/validate/operations.go +++ b/tests/robustness/validate/operations.go @@ -25,7 +25,9 @@ import ( ) func validateOperationHistoryAndReturnVisualize(t *testing.T, lg *zap.Logger, operations []porcupine.Operation) (visualize func(basepath string)) { - linearizable, info := porcupine.CheckOperationsVerbose(model.NonDeterministicModel, operations, 5*time.Minute) + const timeout = 5 * time.Minute + lg.Info("Running porcupine to check operations", zap.String("model", "NonDeterministicModel"), zap.Duration("timeout", timeout)) + linearizable, info := porcupine.CheckOperationsVerbose(model.NonDeterministicModel, operations, timeout) if linearizable == porcupine.Illegal { t.Error("Model is not linearizable") }