From 477e779b9805f8c70717cc984be6f3b1e30202ac Mon Sep 17 00:00:00 2001 From: Cian Johnston Date: Thu, 14 Mar 2024 14:04:08 +0000 Subject: [PATCH 1/3] feat(codersdk): add debug handlers for logs, manifest, and token to agent --- agent/agent.go | 58 ++++++++++++++++++++++++++++++++++ agent/agent_test.go | 55 +++++++++++++++++++++++++++++++- agent/api.go | 3 ++ codersdk/workspaceagentconn.go | 33 +++++++++++++++++++ 4 files changed, 148 insertions(+), 1 deletion(-) diff --git a/agent/agent.go b/agent/agent.go index 820856d42309a..ed80199a78975 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -1699,11 +1699,69 @@ func (a *agent) HandleHTTPMagicsockDebugLoggingState(w http.ResponseWriter, r *h _, _ = fmt.Fprintf(w, "updated magicsock debug logging to %v", stateBool) } +func (a *agent) HandleHTTPDebugManifest(w http.ResponseWriter, _ *http.Request) { + sdkManifest := a.manifest.Load() + if sdkManifest == nil { + w.WriteHeader(http.StatusInternalServerError) + _, _ = fmt.Fprintf(w, "no manifest in-memory") + return + } + + w.WriteHeader(http.StatusOK) + if err := json.NewEncoder(w).Encode(sdkManifest); err != nil { + a.logger.Error(a.hardCtx, "write debug manifest", slog.Error(err)) + } +} + +func (a *agent) HandleHTTPDebugToken(w http.ResponseWriter, _ *http.Request) { + tok := a.sessionToken.Load() + if tok == nil { + w.WriteHeader(http.StatusInternalServerError) + _, _ = fmt.Fprintf(w, "no session token in-memory") + return + } + w.WriteHeader(http.StatusOK) + _, _ = fmt.Fprintf(w, *tok) +} + +func (a *agent) HandleHTTPDebugLogs(w http.ResponseWriter, _ *http.Request) { + f, err := os.Open(filepath.Join(a.logDir, "coder-agent.log")) + if err != nil { + w.WriteHeader(http.StatusInternalServerError) + _, _ = fmt.Fprintf(w, "could not open log file: %s", err) + return + } + + // Cap to the last 10 MB of the log file. + start, err := f.Seek(10*1024*1024, io.SeekEnd) + if err != nil { + w.WriteHeader(http.StatusInternalServerError) + _, _ = fmt.Fprintf(w, "seek log file: %s", err) + return + } + if start < 0 { + start = 0 + } + bs := make([]byte, 10*1024*1024) + _, err = f.ReadAt(bs, start) + if err != nil && !errors.Is(err, io.EOF) { + w.WriteHeader(http.StatusInternalServerError) + _, _ = fmt.Fprintf(w, "read log file: %s", err) + return + } + + w.WriteHeader(http.StatusOK) + _, _ = io.Copy(w, bytes.NewReader(bs)) +} + func (a *agent) HTTPDebug() http.Handler { r := chi.NewRouter() + r.Get("/debug/logs", a.HandleHTTPDebugLogs) r.Get("/debug/magicsock", a.HandleHTTPDebugMagicsock) r.Get("/debug/magicsock/debug-logging/{state}", a.HandleHTTPMagicsockDebugLoggingState) + r.Get("/debug/manifest", a.HandleHTTPDebugManifest) + r.Get("/debug/token", a.HandleHTTPDebugToken) r.NotFound(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusNotFound) _, _ = w.Write([]byte("404 not found")) diff --git a/agent/agent_test.go b/agent/agent_test.go index 5626f52c9311b..7bb3d8a7d7bca 100644 --- a/agent/agent_test.go +++ b/agent/agent_test.go @@ -1978,7 +1978,11 @@ func TestAgent_DebugServer(t *testing.T) { //nolint:dogsled conn, _, _, _, agnt := setupAgent(t, agentsdk.Manifest{ DERPMap: derpMap, - }, 0) + }, 0, func(c *agenttest.Client, o *agent.Options) { + o.ExchangeToken = func(context.Context) (string, error) { + return "token", nil + } + }) awaitReachableCtx := testutil.Context(t, testutil.WaitLong) ok := conn.AwaitReachable(awaitReachableCtx) @@ -2059,6 +2063,55 @@ func TestAgent_DebugServer(t *testing.T) { require.Contains(t, string(resBody), `invalid state "blah", must be a boolean`) }) }) + + t.Run("Manifest", func(t *testing.T) { + t.Parallel() + + ctx := testutil.Context(t, testutil.WaitLong) + req, err := http.NewRequestWithContext(ctx, http.MethodGet, srv.URL+"/debug/manifest", nil) + require.NoError(t, err) + + res, err := srv.Client().Do(req) + require.NoError(t, err) + defer res.Body.Close() + require.Equal(t, http.StatusOK, res.StatusCode) + + var v agentsdk.Manifest + require.NoError(t, json.NewDecoder(res.Body).Decode(&v)) + require.NotNil(t, v) + }) + + t.Run("Token", func(t *testing.T) { + t.Parallel() + + ctx := testutil.Context(t, testutil.WaitLong) + req, err := http.NewRequestWithContext(ctx, http.MethodGet, srv.URL+"/debug/token", nil) + require.NoError(t, err) + + res, err := srv.Client().Do(req) + require.NoError(t, err) + require.Equal(t, http.StatusOK, res.StatusCode) + defer res.Body.Close() + resBody, err := io.ReadAll(res.Body) + require.NoError(t, err) + require.Equal(t, "token", string(resBody)) + }) + + t.Run("Logs", func(t *testing.T) { + t.Parallel() + + ctx := testutil.Context(t, testutil.WaitLong) + req, err := http.NewRequestWithContext(ctx, http.MethodGet, srv.URL+"/debug/logs", nil) + require.NoError(t, err) + + res, err := srv.Client().Do(req) + require.NoError(t, err) + require.Equal(t, http.StatusOK, res.StatusCode) + defer res.Body.Close() + resBody, err := io.ReadAll(res.Body) + require.NoError(t, err) + require.NotEmpty(t, string(resBody)) + }) } func TestAgent_ScriptLogging(t *testing.T) { diff --git a/agent/api.go b/agent/api.go index b81a7b9b44e41..59988e8f06deb 100644 --- a/agent/api.go +++ b/agent/api.go @@ -36,8 +36,11 @@ func (a *agent) apiHandler() http.Handler { cacheDuration: cacheDuration, } r.Get("/api/v0/listening-ports", lp.handler) + r.Get("/debug/logs", a.HandleHTTPDebugLogs) r.Get("/debug/magicsock", a.HandleHTTPDebugMagicsock) r.Get("/debug/magicsock/debug-logging/{state}", a.HandleHTTPMagicsockDebugLoggingState) + r.Get("/debug/manifest", a.HandleHTTPDebugManifest) + r.Get("/debug/token", a.HandleHTTPDebugToken) return r } diff --git a/codersdk/workspaceagentconn.go b/codersdk/workspaceagentconn.go index e5451052bcd7e..09bed58fe66b0 100644 --- a/codersdk/workspaceagentconn.go +++ b/codersdk/workspaceagentconn.go @@ -372,6 +372,39 @@ func (c *WorkspaceAgentConn) DebugMagicsock(ctx context.Context) ([]byte, error) return bs, nil } +// DebugManifest returns the agent's in-memory manifest. Unfortunately this must +// be returns as a []byte to avoid an import cycle. +func (c *WorkspaceAgentConn) DebugManifest(ctx context.Context) ([]byte, error) { + ctx, span := tracing.StartSpan(ctx) + defer span.End() + res, err := c.apiRequest(ctx, http.MethodGet, "/debug/manifest", nil) + if err != nil { + return nil, xerrors.Errorf("do request: %w", err) + } + defer res.Body.Close() + bs, err := io.ReadAll(res.Body) + if err != nil { + return nil, xerrors.Errorf("read response body: %w", err) + } + return bs, nil +} + +// DebugLogs returns up to the last 10MB of `/tmp/coder-agent.log` +func (c *WorkspaceAgentConn) DebugLogs(ctx context.Context) ([]byte, error) { + ctx, span := tracing.StartSpan(ctx) + defer span.End() + res, err := c.apiRequest(ctx, http.MethodGet, "/debug/logs", nil) + if err != nil { + return nil, xerrors.Errorf("do request: %w", err) + } + defer res.Body.Close() + bs, err := io.ReadAll(res.Body) + if err != nil { + return nil, xerrors.Errorf("read response body: %w", err) + } + return bs, nil +} + // apiRequest makes a request to the workspace agent's HTTP API server. func (c *WorkspaceAgentConn) apiRequest(ctx context.Context, method, path string, body io.Reader) (*http.Response, error) { ctx, span := tracing.StartSpan(ctx) From c668d6c3e17719eea159ec08de1e2b657c3b48e8 Mon Sep 17 00:00:00 2001 From: Cian Johnston Date: Thu, 14 Mar 2024 14:19:48 +0000 Subject: [PATCH 2/3] add more logging --- agent/agent.go | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/agent/agent.go b/agent/agent.go index ed80199a78975..3632de462aeeb 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -1699,9 +1699,10 @@ func (a *agent) HandleHTTPMagicsockDebugLoggingState(w http.ResponseWriter, r *h _, _ = fmt.Fprintf(w, "updated magicsock debug logging to %v", stateBool) } -func (a *agent) HandleHTTPDebugManifest(w http.ResponseWriter, _ *http.Request) { +func (a *agent) HandleHTTPDebugManifest(w http.ResponseWriter, r *http.Request) { sdkManifest := a.manifest.Load() if sdkManifest == nil { + a.logger.Error(r.Context(), "no manifest in-memory") w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintf(w, "no manifest in-memory") return @@ -1713,9 +1714,10 @@ func (a *agent) HandleHTTPDebugManifest(w http.ResponseWriter, _ *http.Request) } } -func (a *agent) HandleHTTPDebugToken(w http.ResponseWriter, _ *http.Request) { +func (a *agent) HandleHTTPDebugToken(w http.ResponseWriter, r *http.Request) { tok := a.sessionToken.Load() if tok == nil { + a.logger.Error(r.Context(), "no session token in-memory") w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintf(w, "no session token in-memory") return @@ -1724,17 +1726,21 @@ func (a *agent) HandleHTTPDebugToken(w http.ResponseWriter, _ *http.Request) { _, _ = fmt.Fprintf(w, *tok) } -func (a *agent) HandleHTTPDebugLogs(w http.ResponseWriter, _ *http.Request) { - f, err := os.Open(filepath.Join(a.logDir, "coder-agent.log")) +func (a *agent) HandleHTTPDebugLogs(w http.ResponseWriter, r *http.Request) { + logPath := filepath.Join(a.logDir, "coder-agent.log") + f, err := os.Open(logPath) if err != nil { + a.logger.Error(r.Context(), "open agent log file", slog.Error(err), slog.F("path", logPath)) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintf(w, "could not open log file: %s", err) return } + defer f.Close() // Cap to the last 10 MB of the log file. start, err := f.Seek(10*1024*1024, io.SeekEnd) if err != nil { + a.logger.Error(r.Context(), "seek agent log file", slog.Error(err)) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintf(w, "seek log file: %s", err) return @@ -1745,6 +1751,7 @@ func (a *agent) HandleHTTPDebugLogs(w http.ResponseWriter, _ *http.Request) { bs := make([]byte, 10*1024*1024) _, err = f.ReadAt(bs, start) if err != nil && !errors.Is(err, io.EOF) { + a.logger.Error(r.Context(), "read agent log file", slog.Error(err)) w.WriteHeader(http.StatusInternalServerError) _, _ = fmt.Fprintf(w, "read log file: %s", err) return From 636bb3f000f14e58c800939f8cea46d267e0ef13 Mon Sep 17 00:00:00 2001 From: Cian Johnston Date: Thu, 14 Mar 2024 14:41:02 +0000 Subject: [PATCH 3/3] use io.LimitReader instead of seeking --- agent/agent.go | 21 +++------------------ agent/agent_test.go | 8 ++++++++ 2 files changed, 11 insertions(+), 18 deletions(-) diff --git a/agent/agent.go b/agent/agent.go index 3632de462aeeb..d2f0f7203fcb1 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -1737,28 +1737,13 @@ func (a *agent) HandleHTTPDebugLogs(w http.ResponseWriter, r *http.Request) { } defer f.Close() - // Cap to the last 10 MB of the log file. - start, err := f.Seek(10*1024*1024, io.SeekEnd) - if err != nil { - a.logger.Error(r.Context(), "seek agent log file", slog.Error(err)) - w.WriteHeader(http.StatusInternalServerError) - _, _ = fmt.Fprintf(w, "seek log file: %s", err) - return - } - if start < 0 { - start = 0 - } - bs := make([]byte, 10*1024*1024) - _, err = f.ReadAt(bs, start) + // Limit to 10MB. + w.WriteHeader(http.StatusOK) + _, err = io.Copy(w, io.LimitReader(f, 10*1024*1024)) if err != nil && !errors.Is(err, io.EOF) { a.logger.Error(r.Context(), "read agent log file", slog.Error(err)) - w.WriteHeader(http.StatusInternalServerError) - _, _ = fmt.Fprintf(w, "read log file: %s", err) return } - - w.WriteHeader(http.StatusOK) - _, _ = io.Copy(w, bytes.NewReader(bs)) } func (a *agent) HTTPDebug() http.Handler { diff --git a/agent/agent_test.go b/agent/agent_test.go index 7bb3d8a7d7bca..d0fd422452e8d 100644 --- a/agent/agent_test.go +++ b/agent/agent_test.go @@ -55,6 +55,7 @@ import ( "github.com/coder/coder/v2/agent/proto" "github.com/coder/coder/v2/codersdk" "github.com/coder/coder/v2/codersdk/agentsdk" + "github.com/coder/coder/v2/cryptorand" "github.com/coder/coder/v2/pty/ptytest" "github.com/coder/coder/v2/tailnet" "github.com/coder/coder/v2/tailnet/tailnettest" @@ -1974,6 +1975,11 @@ func TestAgent_WriteVSCodeConfigs(t *testing.T) { func TestAgent_DebugServer(t *testing.T) { t.Parallel() + logDir := t.TempDir() + logPath := filepath.Join(logDir, "coder-agent.log") + randLogStr, err := cryptorand.String(32) + require.NoError(t, err) + require.NoError(t, os.WriteFile(logPath, []byte(randLogStr), 0o600)) derpMap, _ := tailnettest.RunDERPAndSTUN(t) //nolint:dogsled conn, _, _, _, agnt := setupAgent(t, agentsdk.Manifest{ @@ -1982,6 +1988,7 @@ func TestAgent_DebugServer(t *testing.T) { o.ExchangeToken = func(context.Context) (string, error) { return "token", nil } + o.LogDir = logDir }) awaitReachableCtx := testutil.Context(t, testutil.WaitLong) @@ -2111,6 +2118,7 @@ func TestAgent_DebugServer(t *testing.T) { resBody, err := io.ReadAll(res.Body) require.NoError(t, err) require.NotEmpty(t, string(resBody)) + require.Contains(t, string(resBody), randLogStr) }) }