feedBack/docs/plugin-logging.md
Miguel_LZPF b45751164f
fix: address PR #332 review feedback
Addresses 12 of 13 review comments from Copilot and CodeRabbit on
PR #332. One comment (no-manifests in validate-plugins.yml) is
declined and answered inline; the rest are applied here.

Substantive fixes:

- .github/workflows/validate-plugins.yml — add --noconftest to the
  schema-tests step. tests/conftest.py imports structlog at module
  level, but the CI job only installs requirements-test.txt
  (pytest/httpx/jsonschema), so pytest collection would fail at
  conftest import. The schema tests don't use shared fixtures, so
  skipping conftest is safe and avoids dragging the full runtime
  requirements into a 2 KB validation job. (Copilot)

- schema/plugin.schema.json — tighten the server_files regex on both
  settings.server_files and diagnostics.server_files to match the
  runtime _validate_relpath rules in plugins/__init__.py. The
  previous regex only blocked absolute paths, drive letters,
  backslashes, and "..". The runtime also rejects "//", "./",
  "/./", and leading-dotfile segments. Schema-valid manifests are
  now also load-time-valid. Verified the regex against 12 cases:
  the 3 in-tree manifests still validate. (Copilot)

- .claude/skills/plugin-validate/SKILL.md — add a per-iteration
  plugin_ok flag so we no longer print "OK <path>" after an earlier
  FAIL in the same manifest. Schema-pass + id-mismatch previously
  produced both FAIL and OK lines for one plugin. (CodeRabbit)

- docs/websocket-protocol.md — clarify song_info.tuning array length
  is source-dependent (typically 6 guitar, 4 bass, but extended-range
  GP imports can be 7/8/5/6). Recommend highway.getStringCount() for
  the authoritative count. Line 30 already said this; the table row
  on line 12 was the stale half. (CodeRabbit)

Trivial fixes:

- .claude/rules/plugin-author.md — "wants included" -> "wants to
  include" in the settings.server_files rule. (CodeRabbit)

- Markdown MD040 — add `text` language tags to 7 bare-fence code
  blocks across AGENTS.md, docs/PLUGIN_AUTHORING.md,
  docs/testing-plugins.md, docs/plugin-logging.md, .claude/README.md,
  .claude/agents/slopsmith-reviewer.md, and
  .claude/skills/plugin-validate/SKILL.md (two fences). (CodeRabbit)

Declined:

- .github/workflows/validate-plugins.yml no-manifests -> exit 0
  (CodeRabbit suggested exit 1). Plugins in this repo are in-tree,
  not submodules (no .gitmodules, git submodule status empty), and
  the workflow has a path filter on plugins/**/plugin.json so it
  only runs when a manifest actually changes. Exit 0 is correct.
  Answered inline on the PR.

Verification:
  pytest tests/test_plugin_schema.py -v --noconftest    # 8 passed
  python -c "import json,glob,jsonschema; s=json.load(open('schema/plugin.schema.json')); [jsonschema.validate(json.load(open(p)), s) for p in sorted(glob.glob('plugins/*/plugin.json'))]"
  # ok — all 3 in-tree manifests validate against tightened schema
Signed-off-by: Miguel_LZPF <mgcdreamer@gmail.com>
2026-06-18 00:38:51 -07:00

68 lines
2.9 KiB
Markdown

# Plugin logging
Use `context["log"]` for all backend plugin output. It is a stdlib `logging.Logger` namespaced to `slopsmith.plugin.<id>`, pre-configured with the app-wide level, format (including JSON mode), and correlation IDs. **Never use `print()`** — it bypasses correlation context and log rotation.
## Backend usage
```python
def setup(app, context):
log = context["log"]
log.info("plugin ready")
log.warning("optional dependency %r not found, feature disabled", dep)
try:
risky_init()
except Exception:
log.exception("unhandled error during setup") # auto-captures traceback
```
## CLI entry-point fallback
For helper scripts that also run as `__main__`, add a stdlib fallback so the logger works without the server pipeline:
```python
if __name__ == "__main__":
import logging
logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s")
```
## How it's wired
The plugin loader assigns each plugin a logger before calling `setup()`:
```python
context["log"] = logging.getLogger(f"slopsmith.plugin.{plugin_id}")
```
That logger inherits from the root `slopsmith` logger, which is configured by `logging_setup.configure_logging()` (called from `main.py` before uvicorn boots). It respects:
- **`LOG_LEVEL`** — `DEBUG | INFO | WARNING | ERROR` (default `INFO`)
- **`LOG_FORMAT`** — `json | text` (default `text` — coloured console)
- **`LOG_FILE`** — optional path for a persistent log file (e.g. `/config/slopsmith.log`)
- **Correlation IDs** — each HTTP request carries `X-Request-ID`; structlog injects it into every log line during that request's lifetime. WebSocket sessions get their own `ws_conn_id` contextvar bound at accept time.
## Verifying
Look for your plugin's logger name in the console output:
```text
INFO slopsmith.plugin.my_plugin: plugin ready
```
Switch `LOG_FORMAT=json` to see structured output:
```json
{"timestamp": "...", "level": "info", "logger": "slopsmith.plugin.my_plugin", "event": "plugin ready", "request_id": "..."}
```
## Common mistakes
- **Using `print()` inside `setup()` or request handlers.** `print()` goes to stdout, bypasses level filtering, log rotation, JSON formatting, and correlation IDs. Audit your plugin with `grep -nR 'print(' plugins/<id>/`.
- **Creating a new logger with `logging.getLogger("my_plugin")`.** This creates an unparented logger that doesn't inherit slopsmith's configuration. Always use the one passed via `context["log"]`.
- **Logging at `INFO` in hot paths.** Default `LOG_LEVEL` is `INFO`, so `log.info(...)` inside a per-frame or per-message loop floods output. Use `log.debug(...)` for hot-path tracing.
## Related
- [PLUGIN_AUTHORING.md](PLUGIN_AUTHORING.md) — guide index
- [plugin-manifest.md](plugin-manifest.md) — the `routes.py` / `setup(app, context)` contract
- [plugin-diagnostics.md](plugin-diagnostics.md) — capturing logs into the diagnostics bundle