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 etcd-io#13167 is a good example for that.

Signed-off-by: Thomas Jungblut <tjungblu@redhat.com>

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++

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()

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...),

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
 }

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)
 }

tests/framework/e2e/etcd_spawn_nocov.go

@@ -21,23 +21,32 @@ 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
 	}
 	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)
 }