diff --git a/cli/agent.go b/cli/agent.go index fa62761cc1716..0cdfc66c80323 100644 --- a/cli/agent.go +++ b/cli/agent.go @@ -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", diff --git a/cli/agent_test.go b/cli/agent_test.go index a1f519cf4dada..1f366da8b4ced 100644 --- a/cli/agent_test.go +++ b/cli/agent_test.go @@ -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) diff --git a/cli/clibase/cmd.go b/cli/clibase/cmd.go index a2ca36b2c9142..d6789108870f3 100644 --- a/cli/clibase/cmd.go +++ b/cli/clibase/cmd.go @@ -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) diff --git a/cli/clitest/clitest.go b/cli/clitest/clitest.go index 23acc7c01b9d3..451757debf3e1 100644 --- a/cli/clitest/clitest.go +++ b/cli/clitest/clitest.go @@ -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, " ")) diff --git a/cli/exp_scaletest.go b/cli/exp_scaletest.go index 32f3bdd47e062..748fcdb6dc345 100644 --- a/cli/exp_scaletest.go +++ b/cli/exp_scaletest.go @@ -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) } diff --git a/cli/ping.go b/cli/ping.go index 2df0d57446780..94ca23e3aa459 100644 --- a/cli/ping.go +++ b/cli/ping.go @@ -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 { diff --git a/cli/portforward.go b/cli/portforward.go index d47a6acb2280c..73a279200cd5d 100644 --- a/cli/portforward.go +++ b/cli/portforward.go @@ -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 { diff --git a/cli/root.go b/cli/root.go index ecb5e1309a11a..8d645ea5f1d7a 100644 --- a/cli/root.go +++ b/cli/root.go @@ -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 diff --git a/cli/server.go b/cli/server.go index b09f814068343..ab2f7bb01e892 100644 --- a/cli/server.go +++ b/cli/server.go @@ -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() } diff --git a/cli/server_createadminuser.go b/cli/server_createadminuser.go index 3200177b6dc54..7491afac3c3f8 100644 --- a/cli/server_createadminuser.go +++ b/cli/server_createadminuser.go @@ -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) } diff --git a/cli/speedtest.go b/cli/speedtest.go index ca6c5e50a6f05..bfc259dc67eda 100644 --- a/cli/speedtest.go +++ b/cli/speedtest.go @@ -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) } diff --git a/cli/speedtest_test.go b/cli/speedtest_test.go index f16b769cc85e7..66dcab5abbeae 100644 --- a/cli/speedtest_test.go +++ b/cli/speedtest_test.go @@ -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) diff --git a/cli/ssh.go b/cli/ssh.go index 9287ee1ef13c0..0b0a81f2ad83e 100644 --- a/cli/ssh.go +++ b/cli/ssh.go @@ -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 diff --git a/cli/ssh_test.go b/cli/ssh_test.go index 77eae7d3b05fa..0f94fcce90ebd 100644 --- a/cli/ssh_test.go +++ b/cli/ssh_test.go @@ -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) diff --git a/cli/vscodessh.go b/cli/vscodessh.go index 87458d85833af..5a61946cdad3d 100644 --- a/cli/vscodessh.go +++ b/cli/vscodessh.go @@ -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)