fix(scaletest/dashboard): handle hanging when elem not visible

coder · johnstcn · Oct 11, 2023 · Oct 10, 2023 · Oct 10, 2023 · Oct 10, 2023
commit a43b4903aa1940100f4ce5793ee1044cd7e31cc1
diff --git a/cli/exp_scaletest.go b/cli/exp_scaletest.go
@@ -1099,6 +1099,9 @@ func (r *RootCmd) scaletestDashboard() *clibase.Cmd {
 			}
 			ctx := inv.Context()
 			logger := slog.Make(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelInfo)
+			if r.verbose {
+				logger = logger.Leveled(slog.LevelDebug)
+			}
 			tracerProvider, closeTracing, tracingEnabled, err := tracingFlags.provider(ctx)
 			if err != nil {
 				return xerrors.Errorf("create tracer provider: %w", err)
@@ -1200,14 +1203,14 @@ func (r *RootCmd) scaletestDashboard() *clibase.Cmd {
 		{
 			Flag:        "interval",
 			Env:         "CODER_SCALETEST_DASHBOARD_INTERVAL",
-			Default:     "3s",
+			Default:     "10s",
 			Description: "Interval between actions.",
 			Value:       clibase.DurationOf(&interval),
 		},
 		{
 			Flag:        "jitter",
 			Env:         "CODER_SCALETEST_DASHBOARD_JITTER",
-			Default:     "2s",
+			Default:     "5s",
 			Description: "Jitter between actions.",
 			Value:       clibase.DurationOf(&jitter),
 		},

diff --git a/scaletest/dashboard/chromedp.go b/scaletest/dashboard/chromedp.go
@@ -90,13 +90,13 @@ var defaultTargets = []Target{
 // If no elements are found, an error is returned.
 // If more than one element is found, one is chosen at random.
 // The label of the clicked element is returned.
-func ClickRandomElement(ctx context.Context, randIntn func(int) int) (Label, Action, error) {
+func ClickRandomElement(ctx context.Context, log slog.Logger, randIntn func(int) int, deadline time.Time) (Label, Action, error) {
 	var xpath Selector
 	var found bool
 	var err error
 	matches := make([]Target, 0)
 	for _, tgt := range defaultTargets {
-		xpath, found, err = randMatch(ctx, tgt.ClickOn, randIntn)
+		xpath, found, err = randMatch(ctx, log, tgt.ClickOn, randIntn, deadline)
 		if err != nil {
 			return "", nil, xerrors.Errorf("find matches for %q: %w", tgt.ClickOn, err)
 		}
@@ -111,14 +111,20 @@ func ClickRandomElement(ctx context.Context, randIntn func(int) int) (Label, Act
 	}
 
 	if len(matches) == 0 {
+		log.Debug(ctx, "no matches found this time")
 		return "", nil, xerrors.Errorf("no matches found")
 	}
 	match := pick(matches, randIntn)
-	// rely on map iteration order being random
 	act := func(actx context.Context) error {
-		if err := clickAndWait(actx, match.ClickOn, match.WaitFor); err != nil {
+		log.Debug(ctx, "clicking", slog.F("label", match.Label), slog.F("xpath", match.ClickOn))
+		if err := runWithDeadline(ctx, deadline, chromedp.Click(match.ClickOn, chromedp.NodeReady)); err != nil {
+			log.Error(ctx, "click failed", slog.F("label", match.Label), slog.F("xpath", match.ClickOn), slog.Error(err))
 			return xerrors.Errorf("click %q: %w", match.ClickOn, err)
 		}
+		if err := runWithDeadline(ctx, deadline, chromedp.WaitReady(match.WaitFor)); err != nil {
+			log.Error(ctx, "wait failed", slog.F("label", match.Label), slog.F("xpath", match.WaitFor), slog.Error(err))
+			return xerrors.Errorf("wait for %q: %w", match.WaitFor, err)
+		}
 		return nil
 	}
 	return match.Label, act, nil
@@ -128,26 +134,32 @@ func ClickRandomElement(ctx context.Context, randIntn func(int) int) (Label, Act
 // The returned selector is the full XPath of the matched node.
 // If no matches are found, an error is returned.
 // If multiple matches are found, one is chosen at random.
-func randMatch(ctx context.Context, s Selector, randIntn func(int) int) (Selector, bool, error) {
+func randMatch(ctx context.Context, log slog.Logger, s Selector, randIntn func(int) int, deadline time.Time) (Selector, bool, error) {
 	var nodes []*cdp.Node
-	err := chromedp.Run(ctx, chromedp.Nodes(s, &nodes, chromedp.NodeVisible, chromedp.AtLeast(0)))
-	if err != nil {
+	log.Debug(ctx, "getting nodes for selector", slog.F("selector", s))
+	if err := runWithDeadline(ctx, deadline, chromedp.Nodes(s, &nodes, chromedp.NodeReady, chromedp.AtLeast(0))); err != nil {
+		log.Debug(ctx, "failed to get nodes for selector", slog.F("selector", s), slog.Error(err))
 		return "", false, xerrors.Errorf("get nodes for selector %q: %w", s, err)
 	}
 	if len(nodes) == 0 {
+		log.Debug(ctx, "no nodes found for selector", slog.F("selector", s))
 		return "", false, nil
 	}
 	n := pick(nodes, randIntn)
+	log.Debug(ctx, "found node", slog.F("node", n.FullXPath()))
 	return Selector(n.FullXPath()), true, nil
 }
 
-// clickAndWait clicks the given selector and waits for the page to finish loading.
-// The page is considered loaded when the network event "LoadingFinished" is received.
-func clickAndWait(ctx context.Context, clickOn, waitFor Selector) error {
-	return chromedp.Run(ctx, chromedp.Tasks{
-		chromedp.Click(clickOn, chromedp.NodeVisible),
-		chromedp.WaitVisible(waitFor, chromedp.NodeVisible),
-	})
+func waitForWorkspacesPageLoaded(ctx context.Context, deadline time.Time) error {
+	return runWithDeadline(ctx, deadline, chromedp.WaitReady(`tbody.MuiTableBody-root`))
+}
+
+func runWithDeadline(ctx context.Context, deadline time.Time, acts ...chromedp.Action) error {
+	deadlineCtx, deadlineCancel := context.WithDeadline(ctx, deadline)
+	defer deadlineCancel()
+	c := chromedp.FromContext(ctx)
+	tasks := chromedp.Tasks(acts)
+	return tasks.Do(cdp.WithExecutor(deadlineCtx, c.Target))
 }
 
 // initChromeDPCtx initializes a chromedp context with the given session token cookie

diff --git a/scaletest/dashboard/config.go b/scaletest/dashboard/config.go
@@ -21,7 +21,7 @@ type Config struct {
 	// Headless controls headless mode for chromedp.
 	Headless bool `json:"headless"`
 	// ActionFunc is a function that returns an action to run.
-	ActionFunc func(ctx context.Context, randIntn func(int) int) (Label, Action, error) `json:"-"`
+	ActionFunc func(ctx context.Context, log slog.Logger, randIntn func(int) int, deadline time.Time) (Label, Action, error) `json:"-"`
 	// RandIntn is a function that returns a random number between 0 and n-1.
 	RandIntn func(int) int `json:"-"`
 }

diff --git a/scaletest/dashboard/run.go b/scaletest/dashboard/run.go
@@ -53,6 +53,11 @@ func (r *Runner) Run(ctx context.Context, _ string, _ io.Writer) error {
 	defer cdpCancel()
 	t := time.NewTicker(1) // First one should be immediate
 	defer t.Stop()
+	r.cfg.Logger.Info(ctx, "waiting for workspaces page to load")
+	loadWorkspacePageDeadline := time.Now().Add(r.cfg.Interval)
+	if err := waitForWorkspacesPageLoaded(cdpCtx, loadWorkspacePageDeadline); err != nil {
+		return xerrors.Errorf("wait for workspaces page to load: %w", err)
+	}
 	for {
 		select {
 		case <-cdpCtx.Done():
@@ -63,8 +68,9 @@ func (r *Runner) Run(ctx context.Context, _ string, _ io.Writer) error {
 				offset = time.Duration(r.cfg.RandIntn(int(2*r.cfg.Jitter)) - int(r.cfg.Jitter))
 			}
 			wait := r.cfg.Interval + offset
+			actionCompleteByDeadline := time.Now().Add(wait)
 			t.Reset(wait)
-			l, act, err := r.cfg.ActionFunc(cdpCtx, r.cfg.RandIntn)
+			l, act, err := r.cfg.ActionFunc(cdpCtx, r.cfg.Logger, r.cfg.RandIntn, actionCompleteByDeadline)
 			if err != nil {
 				r.cfg.Logger.Error(ctx, "calling ActionFunc", slog.Error(err))
 				continue

diff --git a/scaletest/dashboard/run_test.go b/scaletest/dashboard/run_test.go
@@ -11,6 +11,7 @@ import (
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
+	"cdr.dev/slog"
 	"cdr.dev/slog/sloggers/slogtest"
 	"github.com/coder/coder/v2/coderd/coderdtest"
 	"github.com/coder/coder/v2/scaletest/dashboard"
@@ -51,7 +52,7 @@ func Test_Run(t *testing.T) {
 		Jitter:   100 * time.Millisecond,
 		Logger:   log,
 		Headless: true,
-		ActionFunc: func(_ context.Context, rnd func(int) int) (dashboard.Label, dashboard.Action, error) {
+		ActionFunc: func(_ context.Context, _ slog.Logger, rnd func(int) int, _ time.Time) (dashboard.Label, dashboard.Action, error) {
 			if rnd(2) == 0 {
 				return "fails", failAction, nil
 			}