stability: make debug mode actually useful for troubleshooting #13

Open
opened 2026-05-23 18:50:34 +00:00 by Klaus · 0 comments
Owner

Problem

GITEA_DEBUG=true is the only knob for observability, and it does surprisingly little. Today it only:

  1. Lowers the zap log level to Debug (pkg/log/log.go:59)
  2. Logs the JSON-marshalled tool result via log.Debugf("Text Result: %s", …) in pkg/to/to.go:18
  3. Enables the Gitea SDK's own debug mode (pkg/gitea/gitea.go:50), whose output is written to a separate writer and doesn't merge with the zap log file

When something goes wrong, this isn't enough to diagnose it. Concrete gaps:

  • No log of the incoming tool call. You see the result that came out, but not the tool name, arguments, or which caller invoked it. So you can correlate a 500 response with… nothing.
  • No HTTP request/response logging. No method, URL, status code, duration, or payload size for the upstream Gitea API call. You can't tell if one tool call fanned out into 1 or 5 upstream requests, or which one was slow.
  • No per-call timing. Latency is invisible. "Is Gitea slow or is the MCP server slow?" can't be answered from the log.
  • No request/correlation ID (see also #9). In HTTP mode with concurrent clients, debug lines from different calls interleave with nothing tying them together.
  • Text Result: log is contextless. No tool name, no args, no request id — just a blob of JSON. If three tools fire concurrently you can't tell which result is which.
  • Errors are logged with no extra context. to.ErrorResult (pkg/to/to.go:25) calls log.Errorf("%s", err.Error()) — no tool name, no args, no upstream HTTP details.
  • No startup config dump in debug mode. You can't see what host/mode/port/read-only/insecure values the process actually loaded — useful for "did my env var get picked up?" debugging.
  • No log of which auth path was used (per-request Authorization header vs --token vs GITEA_ACCESS_TOKEN). This matters most in HTTP mode where auth precedence is non-obvious.
  • All-or-nothing. No way to scope debug to a single tool or just to HTTP traffic — you either get everything or nothing.
  • Unstructured. Uses Debugf with format strings; logs can't be parsed/filtered by tool name or status code without regex.
  • Sensitive data isn't redacted (overlap with #5) — turning on debug should not be a footgun for log shipping.

Suggested direction

Treat debug mode as the "show me what's actually happening" switch, not just a log-level toggle. Roughly:

  1. Log every tool invocation at debug level with structured fields: tool, method, args (redacted), request_id, caller_token_source. Log on entry and on exit with duration_ms and status (ok / error / cancelled).
  2. Wrap the shared *http.Transport in pkg/gitea with a RoundTripper that logs each upstream request when debug is on: method, url (token stripped from query), status, duration_ms, bytes_in/out. This replaces (and is far more useful than) gitea.SetDebugMode().
  3. Replace Text Result: blob with a structured entry that includes tool name, request ID, and (truncated) result preview.
  4. Dump effective config at startup when debug is on: host, mode, port, read-only, insecure, token source — once, at info level.
  5. Use zap structured fields (zap.String("tool", …)) instead of sugared Debugf for the common cases so logs are filterable.
  6. Hook the redactor from #5 into both the request logger and the result logger.
  7. (Stretch) environment variable like GITEA_DEBUG_SCOPES=http,tools to scope what's logged, keeping the default true = everything.

Depends on / pairs with: #5 (redaction), #9 (request IDs).

## Problem `GITEA_DEBUG=true` is the only knob for observability, and it does surprisingly little. Today it only: 1. Lowers the zap log level to `Debug` (`pkg/log/log.go:59`) 2. Logs the JSON-marshalled tool *result* via `log.Debugf("Text Result: %s", …)` in `pkg/to/to.go:18` 3. Enables the Gitea SDK's own debug mode (`pkg/gitea/gitea.go:50`), whose output is written to a separate writer and doesn't merge with the zap log file When something goes wrong, this isn't enough to diagnose it. Concrete gaps: - **No log of the incoming tool call.** You see the result that came out, but not the tool name, arguments, or which caller invoked it. So you can correlate a 500 response with… nothing. - **No HTTP request/response logging.** No method, URL, status code, duration, or payload size for the upstream Gitea API call. You can't tell if one tool call fanned out into 1 or 5 upstream requests, or which one was slow. - **No per-call timing.** Latency is invisible. "Is Gitea slow or is the MCP server slow?" can't be answered from the log. - **No request/correlation ID** (see also #9). In HTTP mode with concurrent clients, debug lines from different calls interleave with nothing tying them together. - **`Text Result:` log is contextless.** No tool name, no args, no request id — just a blob of JSON. If three tools fire concurrently you can't tell which result is which. - **Errors are logged with no extra context.** `to.ErrorResult` (`pkg/to/to.go:25`) calls `log.Errorf("%s", err.Error())` — no tool name, no args, no upstream HTTP details. - **No startup config dump in debug mode.** You can't see what host/mode/port/read-only/insecure values the process actually loaded — useful for "did my env var get picked up?" debugging. - **No log of which auth path was used** (per-request `Authorization` header vs `--token` vs `GITEA_ACCESS_TOKEN`). This matters most in HTTP mode where auth precedence is non-obvious. - **All-or-nothing.** No way to scope debug to a single tool or just to HTTP traffic — you either get everything or nothing. - **Unstructured.** Uses `Debugf` with format strings; logs can't be parsed/filtered by tool name or status code without regex. - **Sensitive data isn't redacted** (overlap with #5) — turning on debug should not be a footgun for log shipping. ## Suggested direction Treat debug mode as the "show me what's actually happening" switch, not just a log-level toggle. Roughly: 1. **Log every tool invocation** at debug level with structured fields: `tool`, `method`, `args` (redacted), `request_id`, `caller_token_source`. Log on entry and on exit with `duration_ms` and `status` (ok / error / cancelled). 2. **Wrap the shared `*http.Transport`** in `pkg/gitea` with a `RoundTripper` that logs each upstream request when debug is on: `method`, `url` (token stripped from query), `status`, `duration_ms`, `bytes_in/out`. This replaces (and is far more useful than) `gitea.SetDebugMode()`. 3. **Replace `Text Result:` blob** with a structured entry that includes tool name, request ID, and (truncated) result preview. 4. **Dump effective config at startup** when debug is on: host, mode, port, read-only, insecure, token source — once, at info level. 5. **Use zap structured fields** (`zap.String("tool", …)`) instead of sugared `Debugf` for the common cases so logs are filterable. 6. **Hook the redactor from #5** into both the request logger and the result logger. 7. *(Stretch)* environment variable like `GITEA_DEBUG_SCOPES=http,tools` to scope what's logged, keeping the default `true` = everything. Depends on / pairs with: #5 (redaction), #9 (request IDs).
Sign in to join this conversation.
No Label
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: Klaus/gitea-mcp#13