selfhosted
/
coder
mirror of https://github.com/coder/coder.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

feat: capture cli logs in tests (#10669) 

Adds a Logger to cli Invocation and standardizes CLI commands to use it.  clitest creates a test logger by default so that CLI command logs are captured in the test logs.

CLI commands that do their own log configuration are modified to add sinks to the existing logger, rather than create a new one.  This ensures we still capture logs in CLI tests.
This commit is contained in:
Spike Curtis 2023-11-14 22:56:27 +04:00 committed by GitHub
parent 90b6e86555
commit 4894eda711
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
15 changed files with 38 additions and 48 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
cli/agent.go
View File

@ -116,7 +116,7 @@ func (r *RootCmd) workspaceAgent() *clibase.Cmd {
defer logWriter.Close()
sinks = append(sinks, sloghuman.Sink(logWriter))
logger := slog.Make(sinks...).Leveled(slog.LevelDebug)
logger := inv.Logger.AppendSinks(sinks...).Leveled(slog.LevelDebug)
logger.Info(ctx, "spawning reaper process")
// Do not start a reaper on the child process. It's important
@ -159,7 +159,7 @@ func (r *RootCmd) workspaceAgent() *clibase.Cmd {
defer logWriter.Close()
sinks = append(sinks, sloghuman.Sink(logWriter))
logger := slog.Make(sinks...).Leveled(slog.LevelDebug)
logger := inv.Logger.AppendSinks(sinks...).Leveled(slog.LevelDebug)
version := buildinfo.Version()
logger.Info(ctx, "agent is starting now",

23
cli/agent_test.go
View File

@ -20,7 +20,7 @@ import (
"github.com/coder/coder/v2/coderd/database/dbfake"
"github.com/coder/coder/v2/codersdk"
"github.com/coder/coder/v2/provisionersdk/proto"
"github.com/coder/coder/v2/pty/ptytest"
"github.com/coder/coder/v2/testutil"
)
func TestWorkspaceAgent(t *testing.T) {
@ -44,17 +44,17 @@ func TestWorkspaceAgent(t *testing.T) {
"--log-dir", logDir,
)
pty := ptytest.New(t).Attach(inv)
clitest.Start(t, inv)
ctx := inv.Context()
pty.ExpectMatchContext(ctx, "agent is starting now")
coderdtest.AwaitWorkspaceAgents(t, client, ws.ID)
info, err := os.Stat(filepath.Join(logDir, "coder-agent.log"))
require.NoError(t, err)
require.Greater(t, info.Size(), int64(0))
require.Eventually(t, func() bool {
info, err := os.Stat(filepath.Join(logDir, "coder-agent.log"))
if err != nil {
return false
}
return info.Size() > 0
}, testutil.WaitLong, testutil.IntervalMedium)
})
t.Run("Azure", func(t *testing.T) {
@ -84,6 +84,7 @@ func TestWorkspaceAgent(t *testing.T) {
//nolint:revive,staticcheck
context.WithValue(inv.Context(), "azure-client", metadataClient),
)
ctx := inv.Context()
clitest.Start(t, inv)
coderdtest.AwaitWorkspaceAgents(t, client, ws.ID)
@ -126,6 +127,7 @@ func TestWorkspaceAgent(t *testing.T) {
//nolint:revive,staticcheck
context.WithValue(inv.Context(), "aws-client", metadataClient),
)
clitest.Start(t, inv)
ctx := inv.Context()
coderdtest.AwaitWorkspaceAgents(t, client, ws.ID)
@ -164,8 +166,8 @@ func TestWorkspaceAgent(t *testing.T) {
}},
})
inv, cfg := clitest.New(t, "agent", "--auth", "google-instance-identity", "--agent-url", client.URL.String())
ptytest.New(t).Attach(inv)
clitest.SetupConfig(t, member, cfg)
clitest.Start(t,
inv.WithContext(
//nolint:revive,staticcheck
@ -223,10 +225,7 @@ func TestWorkspaceAgent(t *testing.T) {
// Set the subsystems for the agent.
inv.Environ.Set(agent.EnvAgentSubsystem, fmt.Sprintf("%s,%s", codersdk.AgentSubsystemExectrace, codersdk.AgentSubsystemEnvbox))
pty := ptytest.New(t).Attach(inv)
clitest.Start(t, inv)
pty.ExpectMatchContext(inv.Context(), "agent is starting now")
resources := coderdtest.AwaitWorkspaceAgents(t, client, ws.ID)
require.Len(t, resources, 1)

4
cli/clibase/cmd.go
View File

@ -12,6 +12,8 @@ import (
"testing"
"unicode"
"cdr.dev/slog"
"github.com/spf13/pflag"
"golang.org/x/exp/slices"
"golang.org/x/xerrors"
@ -170,6 +172,7 @@ func (c *Cmd) Invoke(args ...string) *Invocation {
Stdout: io.Discard,
Stderr: io.Discard,
Stdin: strings.NewReader(""),
Logger: slog.Make(),
}
}
@ -185,6 +188,7 @@ type Invocation struct {
Stdout io.Writer
Stderr io.Writer
Stdin io.Reader
Logger slog.Logger
// testing
signalNotifyContext func(parent context.Context, signals ...os.Signal) (ctx context.Context, stop context.CancelFunc)

7
cli/clitest/clitest.go
View File

@ -59,13 +59,18 @@ func NewWithCommand(
t testing.TB, cmd *clibase.Cmd, args ...string,
) (*clibase.Invocation, config.Root) {
configDir := config.Root(t.TempDir())
logger := slogtest.Make(t, nil)
// I really would like to fail test on error logs, but realistically, turning on by default
// in all our CLI tests is going to create a lot of flaky noise.
logger := slogtest.Make(t, &slogtest.Options{IgnoreErrors: true}).
Leveled(slog.LevelDebug).
Named("cli")
i := &clibase.Invocation{
Command: cmd,
Args: append([]string{"--global-config", string(configDir)}, args...),
Stdin: io.LimitReader(nil, 0),
Stdout: (&logWriter{prefix: "stdout", log: logger}),
Stderr: (&logWriter{prefix: "stderr", log: logger}),
Logger: logger,
}
t.Logf("invoking command: %s %s", cmd.Name(), strings.Join(i.Args, " "))

4
cli/exp_scaletest.go
View File

@ -882,7 +882,7 @@ func (r *RootCmd) scaletestWorkspaceTraffic() *clibase.Cmd {
reg := prometheus.NewRegistry()
metrics := workspacetraffic.NewMetrics(reg, "username", "workspace_name", "agent_name")
logger := slog.Make(sloghuman.Sink(io.Discard))
logger := inv.Logger
prometheusSrvClose := ServeHandler(ctx, logger, promhttp.HandlerFor(reg, promhttp.HandlerOpts{}), prometheusFlags.Address, "prometheus")
defer prometheusSrvClose()
@ -1075,7 +1075,7 @@ func (r *RootCmd) scaletestDashboard() *clibase.Cmd {
return xerrors.Errorf("--jitter must be less than --interval")
}
ctx := inv.Context()
logger := slog.Make(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelInfo)
logger := inv.Logger.AppendSinks(sloghuman.Sink(inv.Stdout))
if r.verbose {
logger = logger.Leveled(slog.LevelDebug)
}

4
cli/ping.go
View File

@ -46,9 +46,9 @@ func (r *RootCmd) ping() *clibase.Cmd {
return err
}
var logger slog.Logger
logger := inv.Logger
if r.verbose {
logger = slog.Make(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug)
logger = logger.AppendSinks(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug)
}
if r.disableDirect {

4
cli/portforward.go
View File

@ -98,9 +98,9 @@ func (r *RootCmd) portForward() *clibase.Cmd {
return xerrors.Errorf("await agent: %w", err)
}
logger := slog.Make()
logger := inv.Logger
if r.verbose {
logger = slog.Make(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug)
logger = logger.AppendSinks(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug)
}
if r.disableDirect {

16
cli/root.go
View File

@ -30,7 +30,6 @@ import (
"github.com/coder/pretty"
"cdr.dev/slog"
"github.com/coder/coder/v2/buildinfo"
"github.com/coder/coder/v2/cli/clibase"
"github.com/coder/coder/v2/cli/cliui"
@ -442,21 +441,6 @@ func (r *RootCmd) Command(subcommands []*clibase.Cmd) (*clibase.Cmd, error) {
return cmd, nil
}
type contextKey int
const (
contextKeyLogger contextKey = iota
)
func ContextWithLogger(ctx context.Context, l slog.Logger) context.Context {
return context.WithValue(ctx, contextKeyLogger, l)
}
func LoggerFromContext(ctx context.Context) (slog.Logger, bool) {
l, ok := ctx.Value(contextKeyLogger).(slog.Logger)
return l, ok
}
// RootCmd contains parameters and helpers useful to all commands.
type RootCmd struct {
clientURL *url.URL

4
cli/server.go
View File

@ -1092,7 +1092,7 @@ func (r *RootCmd) Server(newAPI func(context.Context, *coderd.Options) (*coderd.
ctx := inv.Context()
cfg := r.createConfig()
logger := slog.Make(sloghuman.Sink(inv.Stderr))
logger := inv.Logger.AppendSinks(sloghuman.Sink(inv.Stderr))
if ok, _ := inv.ParsedFlags().GetBool(varVerbose); ok {
logger = logger.Leveled(slog.LevelDebug)
}
@ -2063,7 +2063,7 @@ func BuildLogger(inv *clibase.Invocation, cfg *codersdk.DeploymentValues) (slog.
level = slog.LevelDebug
}
return slog.Make(filter).Leveled(level), func() {
return inv.Logger.AppendSinks(filter).Leveled(level), func() {
for _, closer := range closers {
_ = closer()
}

2
cli/server_createadminuser.go
View File

@ -42,7 +42,7 @@ func (r *RootCmd) newCreateAdminUserCommand() *clibase.Cmd {
}
cfg := r.createConfig()
logger := slog.Make(sloghuman.Sink(inv.Stderr))
logger := inv.Logger.AppendSinks(sloghuman.Sink(inv.Stderr))
if r.verbose {
logger = logger.Leveled(slog.LevelDebug)
}

5
cli/speedtest.go
View File

@ -48,10 +48,7 @@ func (r *RootCmd) speedtest() *clibase.Cmd {
return xerrors.Errorf("await agent: %w", err)
}
logger, ok := LoggerFromContext(ctx)
if !ok {
logger = slog.Make(sloghuman.Sink(inv.Stderr))
}
logger := inv.Logger.AppendSinks(sloghuman.Sink(inv.Stderr))
if r.verbose {
logger = logger.Leveled(slog.LevelDebug)
}

3
cli/speedtest_test.go
View File

@ -10,7 +10,6 @@ import (
"cdr.dev/slog"
"cdr.dev/slog/sloggers/slogtest"
"github.com/coder/coder/v2/agent/agenttest"
"github.com/coder/coder/v2/cli"
"github.com/coder/coder/v2/cli/clitest"
"github.com/coder/coder/v2/coderd/coderdtest"
"github.com/coder/coder/v2/codersdk"
@ -50,7 +49,7 @@ func TestSpeedtest(t *testing.T) {
ctx, cancel = context.WithTimeout(context.Background(), testutil.WaitLong)
defer cancel()
ctx = cli.ContextWithLogger(ctx, slogtest.Make(t, nil).Named("speedtest").Leveled(slog.LevelDebug))
inv.Logger = slogtest.Make(t, nil).Named("speedtest").Leveled(slog.LevelDebug)
cmdDone := tGo(t, func() {
err := inv.WithContext(ctx).Run()
assert.NoError(t, err)

2
cli/ssh.go
View File

@ -74,7 +74,7 @@ func (r *RootCmd) ssh() *clibase.Cmd {
ctx, cancel := context.WithCancel(ctx)
defer cancel()
logger := slog.Make() // empty logger
logger := inv.Logger
defer func() {
if retErr != nil {
// catch and log all returned errors so we see them in the

2
cli/ssh_test.go
View File

@ -215,6 +215,7 @@ func TestSSH(t *testing.T) {
inv.Stdin = clientOutput
inv.Stdout = serverInput
inv.Stderr = io.Discard
cmdDone := tGo(t, func() {
err := inv.WithContext(ctx).Run()
assert.NoError(t, err)
@ -390,6 +391,7 @@ func TestSSH(t *testing.T) {
inv.Stdin = clientOutput
inv.Stdout = serverInput
inv.Stderr = io.Discard
cmdDone := tGo(t, func() {
err := inv.WithContext(ctx).Run()
assert.NoError(t, err)

2
cli/vscodessh.go
View File

@ -138,7 +138,7 @@ func (r *RootCmd) vscodeSSH() *clibase.Cmd {
// command via the ProxyCommand SSH option.
pid := os.Getppid()
logger := slog.Make()
logger := inv.Logger
if logDir != "" {
logFilePath := filepath.Join(logDir, fmt.Sprintf("%d.log", pid))
logFile, err := fs.OpenFile(logFilePath, os.O_CREATE|os.O_WRONLY, 0o600)