fix(scaletest/dashboard): increase viewport size and handle deadlines (#10197)

- Set viewport size to avoid responsive mode
- Added way more debug logging
- Added facility to write a screenshot on error in verbose mode.
- Added a deadline for each iteraction of clicking on and waiting for a thing.

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)
@@ -1148,16 +1151,20 @@ func (r *RootCmd) scaletestDashboard() *clibase.Cmd {
 				userClient.SetSessionToken(userTokResp.Key)
 
 				config := dashboard.Config{
-					Interval:   interval,
+					Interval: interval,
-					Jitter:     jitter,
+					Jitter:   jitter,
-					Trace:      tracingEnabled,
+					Trace:    tracingEnabled,
-					Logger:     logger.Named(name),
+					Logger:   logger.Named(name),
-					Headless:   headless,
+					Headless: headless,
-					ActionFunc: dashboard.ClickRandomElement,
+					RandIntn: rndGen.Intn,
-					RandIntn:   rndGen.Intn,
+				}
+				// Only take a screenshot if we're in verbose mode.
+				// This could be useful for debugging, but it will blow up the disk.
+				if r.verbose {
+					config.Screenshot = dashboard.Screenshot
 				}
 				//nolint:gocritic
-				logger.Info(ctx, "runner config", slog.F("min_wait", interval), slog.F("max_wait", jitter), slog.F("headless", headless), slog.F("trace", tracingEnabled))
+				logger.Info(ctx, "runner config", slog.F("interval", interval), slog.F("jitter", jitter), slog.F("headless", headless), slog.F("trace", tracingEnabled))
 				if err := config.Validate(); err != nil {
 					return err
 				}
@@ -1200,14 +1207,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),
 		},

scaletest/dashboard/chromedp.go

@@ -2,8 +2,10 @@ package dashboard
 
 import (
 	"context"
+	"fmt"
 	"net/url"
 	"os"
+	"path/filepath"
 	"time"
 
 	"github.com/chromedp/cdproto/cdp"
@@ -11,6 +13,8 @@ import (
 	"github.com/chromedp/chromedp"
 	"golang.org/x/xerrors"
 
+	"github.com/coder/coder/v2/cryptorand"
+
 	"cdr.dev/slog"
 )
 
@@ -86,17 +90,17 @@ var defaultTargets = []Target{
 	},
 }
 
-// ClickRandomElement returns an action that will click an element from defaultTargets.
+// clickRandomElement returns an action that will click an element from defaultTargets.
 // 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 +115,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 +138,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)))
+	log.Debug(ctx, "getting nodes for selector", slog.F("selector", s))
-	if err != nil {
+	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.
+func waitForWorkspacesPageLoaded(ctx context.Context, deadline time.Time) error {
-// The page is considered loaded when the network event "LoadingFinished" is received.
+	return runWithDeadline(ctx, deadline, chromedp.WaitReady(`tbody.MuiTableBody-root`))
-func clickAndWait(ctx context.Context, clickOn, waitFor Selector) error {
+}
-	return chromedp.Run(ctx, chromedp.Tasks{
+
-		chromedp.Click(clickOn, chromedp.NodeVisible),
+func runWithDeadline(ctx context.Context, deadline time.Time, acts ...chromedp.Action) error {
-		chromedp.WaitVisible(waitFor, chromedp.NodeVisible),
+	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
@@ -178,6 +194,13 @@ func initChromeDPCtx(ctx context.Context, log slog.Logger, u *url.URL, sessionTo
 		}
 	}
 
+	// force a viewport size of 1024x768 so we don't go into mobile mode
+	if err := chromedp.Run(cdpCtx, chromedp.EmulateViewport(1024, 768)); err != nil {
+		cancelFunc()
+		allocCtxCancel()
+		return nil, nil, xerrors.Errorf("set viewport size: %w", err)
+	}
+
 	// set cookies
 	if err := setSessionTokenCookie(cdpCtx, sessionToken, u.Host); err != nil {
 		cancelFunc()
@@ -209,6 +232,34 @@ func visitMainPage(ctx context.Context, u *url.URL) error {
 	return chromedp.Run(ctx, chromedp.Navigate(u.String()))
 }
 
+func Screenshot(ctx context.Context, name string) (string, error) {
+	var buf []byte
+	if err := chromedp.Run(ctx, chromedp.CaptureScreenshot(&buf)); err != nil {
+		return "", xerrors.Errorf("capture screenshot: %w", err)
+	}
+	randExt, err := cryptorand.String(4)
+	if err != nil {
+		// this should never happen
+		return "", xerrors.Errorf("generate random string: %w", err)
+	}
+	fname := fmt.Sprintf("scaletest-dashboard-%s-%s-%s.png", name, time.Now().Format("20060102-150405"), randExt)
+	pwd, err := os.Getwd()
+	if err != nil {
+		return "", xerrors.Errorf("get working directory: %w", err)
+	}
+	fpath := filepath.Join(pwd, fname)
+	f, err := os.OpenFile(fpath, os.O_CREATE|os.O_WRONLY, 0o644)
+	if err != nil {
+		return "", xerrors.Errorf("open file: %w", err)
+	}
+	defer f.Close()
+	if _, err := f.Write(buf); err != nil {
+		return "", xerrors.Errorf("write file: %w", err)
+	}
+
+	return fpath, nil
+}
+
 // pick chooses a random element from a slice.
 // If the slice is empty, it returns the zero value of the type.
 func pick[T any](s []T, randIntn func(int) int) T {

scaletest/dashboard/config.go

@@ -21,7 +21,11 @@ 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:"-"`
+	// WaitLoaded is a function that waits for the page to be loaded.
+	WaitLoaded func(ctx context.Context, deadline time.Time) error
+	// Screenshot is a function that takes a screenshot.
+	Screenshot func(ctx context.Context, filename string) (string, error)
 	// RandIntn is a function that returns a random number between 0 and n-1.
 	RandIntn func(int) int `json:"-"`
 }

scaletest/dashboard/run.go

@@ -2,6 +2,7 @@ package dashboard
 
 import (
 	"context"
+	"errors"
 	"io"
 	"time"
 
@@ -25,6 +26,15 @@ var (
 
 func NewRunner(client *codersdk.Client, metrics Metrics, cfg Config) *Runner {
 	client.Trace = cfg.Trace
+	if cfg.WaitLoaded == nil {
+		cfg.WaitLoaded = waitForWorkspacesPageLoaded
+	}
+	if cfg.ActionFunc == nil {
+		cfg.ActionFunc = clickRandomElement
+	}
+	if cfg.Screenshot == nil {
+		cfg.Screenshot = Screenshot
+	}
 	return &Runner{
 		client:  client,
 		cfg:     cfg,
@@ -33,6 +43,16 @@ func NewRunner(client *codersdk.Client, metrics Metrics, cfg Config) *Runner {
 }
 
 func (r *Runner) Run(ctx context.Context, _ string, _ io.Writer) error {
+	err := r.runUntilDeadlineExceeded(ctx)
+	// If the context deadline exceeded, don't return an error.
+	// This just means the test finished.
+	if err == nil || errors.Is(err, context.DeadlineExceeded) {
+		return nil
+	}
+	return err
+}
+
+func (r *Runner) runUntilDeadlineExceeded(ctx context.Context) error {
 	if r.client == nil {
 		return xerrors.Errorf("client is nil")
 	}
@@ -53,6 +73,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 := r.cfg.WaitLoaded(cdpCtx, loadWorkspacePageDeadline); err != nil {
+		return xerrors.Errorf("wait for workspaces page to load: %w", err)
+	}
 	for {
 		select {
 		case <-cdpCtx.Done():
@@ -63,10 +88,16 @@ 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))
+				sPath, sErr := r.cfg.Screenshot(cdpCtx, me.Username)
+				if sErr != nil {
+					r.cfg.Logger.Error(ctx, "screenshot failed", slog.Error(sErr))
+				}
+				r.cfg.Logger.Info(ctx, "screenshot saved", slog.F("path", sPath))
 				continue
 			}
 			start := time.Now()
@@ -77,6 +108,11 @@ func (r *Runner) Run(ctx context.Context, _ string, _ io.Writer) error {
 				r.metrics.IncErrors(string(l))
 				//nolint:gocritic
 				r.cfg.Logger.Error(ctx, "action failed", slog.F("label", l), slog.Error(err))
+				sPath, sErr := r.cfg.Screenshot(cdpCtx, me.Username+"-"+string(l))
+				if sErr != nil {
+					r.cfg.Logger.Error(ctx, "screenshot failed", slog.Error(sErr))
+				}
+				r.cfg.Logger.Info(ctx, "screenshot saved", slog.F("path", sPath))
 			} else {
 				//nolint:gocritic
 				r.cfg.Logger.Info(ctx, "action success", slog.F("label", l))

scaletest/dashboard/run_test.go

@@ -5,12 +5,14 @@ import (
 	"math/rand"
 	"runtime"
 	"sync"
+	"sync/atomic"
 	"testing"
 	"time"
 
 	"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"
@@ -46,17 +48,29 @@ func Test_Run(t *testing.T) {
 		IgnoreErrors: true,
 	})
 	m := &testMetrics{}
+	var (
+		waitLoadedCalled atomic.Bool
+		screenshotCalled atomic.Bool
+	)
 	cfg := dashboard.Config{
 		Interval: 500 * time.Millisecond,
 		Jitter:   100 * time.Millisecond,
 		Logger:   log,
 		Headless: true,
-		ActionFunc: func(_ context.Context, rnd func(int) int) (dashboard.Label, dashboard.Action, error) {
+		WaitLoaded: func(_ context.Context, _ time.Time) error {
+			waitLoadedCalled.Store(true)
+			return nil
+		},
+		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
 			}
 			return "succeeds", successAction, nil
 		},
+		Screenshot: func(_ context.Context, name string) (string, error) {
+			screenshotCalled.Store(true)
+			return "/fake/path/to/" + name + ".png", nil
+		},
 		RandIntn: rg.Intn,
 	}
 	r := dashboard.NewRunner(client, m, cfg)