From 51933a7c8bc3fdb4ad60693b99cabe2df34b6127 Mon Sep 17 00:00:00 2001 From: Thomas Jungblut Date: Mon, 1 Aug 2022 15:53:30 +0200 Subject: [PATCH] Add test name to e2e cluster members This should aid in debugging test flakes, especially in tests where the process is restarted very often and thus changes its pid. Now it's a lot easier to grep for different members, also when different tests fail at the same time. The test TestDowngradeUpgradeClusterOf3 as mentioned in #13167 is a good example for that. Signed-off-by: Thomas Jungblut --- pkg/expect/expect.go | 15 +++++++++++---- tests/framework/e2e/cluster.go | 10 ++++++++-- tests/framework/e2e/cluster_proxy.go | 8 ++++++-- tests/framework/e2e/etcd_process.go | 15 ++++++++------- tests/framework/e2e/etcd_spawn.go | 11 +++++++++-- tests/framework/e2e/etcd_spawn_nocov.go | 21 +++++++++++++++------ 6 files changed, 57 insertions(+), 23 deletions(-) diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go index 648dea34fa1..9d748be7e31 100644 --- a/pkg/expect/expect.go +++ b/pkg/expect/expect.go @@ -33,6 +33,8 @@ import ( const DEBUG_LINES_TAIL = 40 type ExpectProcess struct { + name string + cmd *exec.Cmd fpty *os.File wg sync.WaitGroup @@ -48,15 +50,16 @@ type ExpectProcess struct { // NewExpect creates a new process for expect testing. func NewExpect(name string, arg ...string) (ep *ExpectProcess, err error) { - // if env[] is nil, use current system env - return NewExpectWithEnv(name, arg, nil) + // if env[] is nil, use current system env and the default command as name + return NewExpectWithEnv(name, arg, nil, name) } // NewExpectWithEnv creates a new process with user defined env variables for expect testing. -func NewExpectWithEnv(name string, args []string, env []string) (ep *ExpectProcess, err error) { +func NewExpectWithEnv(name string, args []string, env []string, serverProcessConfigName string) (ep *ExpectProcess, err error) { cmd := exec.Command(name, args...) cmd.Env = env ep = &ExpectProcess{ + name: serverProcessConfigName, cmd: cmd, StopSignal: syscall.SIGTERM, } @@ -72,6 +75,10 @@ func NewExpectWithEnv(name string, args []string, env []string) (ep *ExpectProce return ep, nil } +func (ep *ExpectProcess) Pid() int { + return ep.cmd.Process.Pid +} + func (ep *ExpectProcess) read() { defer ep.wg.Done() printDebugLines := os.Getenv("EXPECT_DEBUG") != "" @@ -81,7 +88,7 @@ func (ep *ExpectProcess) read() { ep.mu.Lock() if l != "" { if printDebugLines { - fmt.Printf("%s-%d: %s", ep.cmd.Path, ep.cmd.Process.Pid, l) + fmt.Printf("%s (%s) (%d): %s", ep.cmd.Path, ep.name, ep.cmd.Process.Pid, l) } ep.lines = append(ep.lines, l) ep.count++ diff --git a/tests/framework/e2e/cluster.go b/tests/framework/e2e/cluster.go index 411bc34b1ce..fb4b64a7392 100644 --- a/tests/framework/e2e/cluster.go +++ b/tests/framework/e2e/cluster.go @@ -19,13 +19,15 @@ import ( "net/url" "os" "path" + "regexp" "strings" "testing" "time" - "go.etcd.io/etcd/server/v3/etcdserver" "go.uber.org/zap" "go.uber.org/zap/zaptest" + + "go.etcd.io/etcd/server/v3/etcdserver" ) const EtcdProcessBasePort = 20000 @@ -38,6 +40,9 @@ const ( ClientTLSAndNonTLS ) +// allow alphanumerics, underscores and dashes +var testNameCleanRegex = regexp.MustCompile(`[^a-zA-Z0-9 \-_]+`) + func NewConfigNoTLS() *EtcdProcessClusterConfig { return &EtcdProcessClusterConfig{ClusterSize: 3, InitialToken: "new", @@ -284,7 +289,8 @@ func (cfg *EtcdProcessClusterConfig) EtcdServerProcessConfigs(tb testing.TB) []* } purl := url.URL{Scheme: cfg.PeerScheme(), Host: fmt.Sprintf("localhost:%d", port+1)} - name := fmt.Sprintf("test-%d", i) + + name := fmt.Sprintf("%s-test-%d", testNameCleanRegex.ReplaceAllString(tb.Name(), ""), i) dataDirPath := cfg.DataDirPath if cfg.DataDirPath == "" { dataDirPath = tb.TempDir() diff --git a/tests/framework/e2e/cluster_proxy.go b/tests/framework/e2e/cluster_proxy.go index 2c4e603e13d..9920ede874d 100644 --- a/tests/framework/e2e/cluster_proxy.go +++ b/tests/framework/e2e/cluster_proxy.go @@ -26,8 +26,9 @@ import ( "strconv" "strings" - "go.etcd.io/etcd/pkg/v3/expect" "go.uber.org/zap" + + "go.etcd.io/etcd/pkg/v3/expect" ) type proxyEtcdProcess struct { @@ -109,6 +110,7 @@ func (p *proxyEtcdProcess) Logs() LogsExpect { type proxyProc struct { lg *zap.Logger + name string execPath string args []string ep string @@ -124,7 +126,7 @@ func (pp *proxyProc) start() error { if pp.proc != nil { panic("already started") } - proc, err := SpawnCmdWithLogger(pp.lg, append([]string{pp.execPath}, pp.args...), nil) + proc, err := SpawnCmdWithLogger(pp.lg, append([]string{pp.execPath}, pp.args...), nil, pp.name) if err != nil { return err } @@ -188,6 +190,7 @@ func newProxyV2Proc(cfg *EtcdServerProcessConfig) *proxyV2Proc { } return &proxyV2Proc{ proxyProc: proxyProc{ + name: cfg.Name, lg: cfg.lg, execPath: cfg.ExecPath, args: append(args, cfg.TlsArgs...), @@ -251,6 +254,7 @@ func newProxyV3Proc(cfg *EtcdServerProcessConfig) *proxyV3Proc { return &proxyV3Proc{ proxyProc{ + name: cfg.Name, lg: cfg.lg, execPath: cfg.ExecPath, args: append(args, tlsArgs...), diff --git a/tests/framework/e2e/etcd_process.go b/tests/framework/e2e/etcd_process.go index d80710c4048..69426066e3f 100644 --- a/tests/framework/e2e/etcd_process.go +++ b/tests/framework/e2e/etcd_process.go @@ -19,9 +19,10 @@ import ( "net/url" "os" + "go.uber.org/zap" + "go.etcd.io/etcd/client/pkg/v3/fileutil" "go.etcd.io/etcd/pkg/v3/expect" - "go.uber.org/zap" ) var ( @@ -100,33 +101,33 @@ func (ep *EtcdServerProcess) Start() error { panic("already started") } ep.cfg.lg.Info("starting server...", zap.String("name", ep.cfg.Name)) - proc, err := SpawnCmdWithLogger(ep.cfg.lg, append([]string{ep.cfg.ExecPath}, ep.cfg.Args...), ep.cfg.EnvVars) + proc, err := SpawnCmdWithLogger(ep.cfg.lg, append([]string{ep.cfg.ExecPath}, ep.cfg.Args...), ep.cfg.EnvVars, ep.cfg.Name) if err != nil { return err } ep.proc = proc err = ep.waitReady() if err == nil { - ep.cfg.lg.Info("started server.", zap.String("name", ep.cfg.Name)) + ep.cfg.lg.Info("started server.", zap.String("name", ep.cfg.Name), zap.Int("pid", ep.proc.Pid())) } return err } func (ep *EtcdServerProcess) Restart() error { - ep.cfg.lg.Info("restaring server...", zap.String("name", ep.cfg.Name)) + ep.cfg.lg.Info("restarting server...", zap.String("name", ep.cfg.Name)) if err := ep.Stop(); err != nil { return err } ep.donec = make(chan struct{}) err := ep.Start() if err == nil { - ep.cfg.lg.Info("restared server", zap.String("name", ep.cfg.Name)) + ep.cfg.lg.Info("restarted server", zap.String("name", ep.cfg.Name)) } return err } func (ep *EtcdServerProcess) Stop() (err error) { - ep.cfg.lg.Info("stoping server...", zap.String("name", ep.cfg.Name)) + ep.cfg.lg.Info("stopping server...", zap.String("name", ep.cfg.Name)) if ep == nil || ep.proc == nil { return nil } @@ -174,7 +175,7 @@ func (ep *EtcdServerProcess) Config() *EtcdServerProcessConfig { return ep.cfg } func (ep *EtcdServerProcess) Logs() LogsExpect { if ep.proc == nil { - ep.cfg.lg.Panic("Please grap logs before process is stopped") + ep.cfg.lg.Panic("Please grab logs before process is stopped") } return ep.proc } diff --git a/tests/framework/e2e/etcd_spawn.go b/tests/framework/e2e/etcd_spawn.go index f8d1e472b5c..ab86df150a2 100644 --- a/tests/framework/e2e/etcd_spawn.go +++ b/tests/framework/e2e/etcd_spawn.go @@ -15,10 +15,17 @@ package e2e import ( - "go.etcd.io/etcd/pkg/v3/expect" + "strings" + "go.uber.org/zap" + + "go.etcd.io/etcd/pkg/v3/expect" ) func SpawnCmd(args []string, envVars map[string]string) (*expect.ExpectProcess, error) { - return SpawnCmdWithLogger(zap.NewNop(), args, envVars) + return SpawnNamedCmd(strings.Join(args, "_"), args, envVars) +} + +func SpawnNamedCmd(processName string, args []string, envVars map[string]string) (*expect.ExpectProcess, error) { + return SpawnCmdWithLogger(zap.NewNop(), args, envVars, processName) } diff --git a/tests/framework/e2e/etcd_spawn_nocov.go b/tests/framework/e2e/etcd_spawn_nocov.go index 6df08539de6..d050e8b5221 100644 --- a/tests/framework/e2e/etcd_spawn_nocov.go +++ b/tests/framework/e2e/etcd_spawn_nocov.go @@ -21,13 +21,14 @@ import ( "os" "strings" - "go.etcd.io/etcd/pkg/v3/expect" "go.uber.org/zap" + + "go.etcd.io/etcd/pkg/v3/expect" ) const noOutputLineCount = 0 // regular binaries emit no extra lines -func SpawnCmdWithLogger(lg *zap.Logger, args []string, envVars map[string]string) (*expect.ExpectProcess, error) { +func SpawnCmdWithLogger(lg *zap.Logger, args []string, envVars map[string]string, name string) (*expect.ExpectProcess, error) { wd, err := os.Getwd() if err != nil { return nil, err @@ -35,9 +36,17 @@ func SpawnCmdWithLogger(lg *zap.Logger, args []string, envVars map[string]string env := mergeEnvVariables(envVars) if strings.HasSuffix(args[0], "/etcdctl3") { env = append(env, "ETCDCTL_API=3") - lg.Info("spawning process with ETCDCTL_API=3", zap.Strings("args", args), zap.String("working-dir", wd), zap.Strings("environment-variables", env)) - return expect.NewExpectWithEnv(CtlBinPath, args[1:], env) + lg.Info("spawning process with ETCDCTL_API=3", + zap.Strings("args", args), + zap.String("working-dir", wd), + zap.String("name", name), + zap.Strings("environment-variables", env)) + return expect.NewExpectWithEnv(CtlBinPath, args[1:], env, name) } - lg.Info("spawning process", zap.Strings("args", args), zap.String("working-dir", wd), zap.Strings("environment-variables", env)) - return expect.NewExpectWithEnv(args[0], args[1:], env) + lg.Info("spawning process", + zap.Strings("args", args), + zap.String("working-dir", wd), + zap.String("name", name), + zap.Strings("environment-variables", env)) + return expect.NewExpectWithEnv(args[0], args[1:], env, name) }