diff --git a/openspec/changes/add-debug-logs-specfact-home/CHANGE_VALIDATION.md b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/CHANGE_VALIDATION.md similarity index 100% rename from openspec/changes/add-debug-logs-specfact-home/CHANGE_VALIDATION.md rename to openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/CHANGE_VALIDATION.md diff --git a/openspec/changes/add-debug-logs-specfact-home/design.md b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/design.md similarity index 100% rename from openspec/changes/add-debug-logs-specfact-home/design.md rename to openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/design.md diff --git a/openspec/changes/add-debug-logs-specfact-home/proposal.md b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/proposal.md similarity index 100% rename from openspec/changes/add-debug-logs-specfact-home/proposal.md rename to openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/proposal.md diff --git a/openspec/changes/add-debug-logs-specfact-home/specs/debug-logging/spec.md b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/specs/debug-logging/spec.md similarity index 100% rename from openspec/changes/add-debug-logs-specfact-home/specs/debug-logging/spec.md rename to openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/specs/debug-logging/spec.md diff --git a/openspec/changes/add-debug-logs-specfact-home/tasks.md b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/tasks.md similarity index 97% rename from openspec/changes/add-debug-logs-specfact-home/tasks.md rename to openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/tasks.md index 825743b..7e6ec37 100644 --- a/openspec/changes/add-debug-logs-specfact-home/tasks.md +++ b/openspec/changes/archive/2026-01-29-add-debug-logs-specfact-home/tasks.md @@ -31,7 +31,7 @@ - [x] 4.1.3 In `src/specfact_cli/commands/backlog_commands.py`, when debug is on, log file read/write for export/import (path, prepared/finished/failed, status, error). - [x] 4.1.4 In `src/specfact_cli/commands/init.py`, when debug is on, ensure template resolution steps are also written to debug log (in addition to existing `debug_print()`); add debug_log_operation for template resolution status with caller. - [x] 4.1.5 Run `hatch run format` and `hatch run type-check` -- [ ] 4.1.6 Apply the **debug log standard** consistently to remaining command modules and adapters: analyze, contract_cmd, drift, enforce, generate, import_cmd, migrate, plan, project_cmd, repro, sdd, spec, sync, update, validate. For each: log started/prepared → attempt (if multi-step) → success or failed with reason/error; include all context needed for anomaly analysis and bug reports (operation, target, status, error, extra: payload/response/reason sanitized). File ops: prepared → finished/failed. API ops: attempt → success/failed with payload, response, reason. No single-line INFO-style entries; every significant operation must have full context (see design “Debug log standard” and auth azure-devops reference). +- [x] 4.1.6 Apply the **debug log standard** consistently to remaining command modules and adapters: analyze, contract_cmd, drift, enforce, generate, import_cmd, migrate, plan, project_cmd, repro, sdd, spec, sync, update, validate. For each: log started/prepared → attempt (if multi-step) → success or failed with reason/error; include all context needed for anomaly analysis and bug reports (operation, target, status, error, extra: payload/response/reason sanitized). File ops: prepared → finished/failed. API ops: attempt → success/failed with payload, response, reason. No single-line INFO-style entries; every significant operation must have full context (see design “Debug log standard” and auth azure-devops reference). ## 5. Tests and quality @@ -46,4 +46,4 @@ - [x] 6.1.2 Update versions and increase patch version. Sync versions across `pyproject.toml`, `setup.py`, `src/__init__.py`, and `src/specfact_cli/__init__.py`. - [x] 6.1.3 Update CHANGELOG.md with new behavior and use the new patch version from 6.1.2. - [x] 6.1.4 Add `docs/reference/debug-logging.md` (user and developer reference); link from `docs/reference/commands.md`, `docs/reference/README.md`, `docs/reference/directory-structure.md`, `docs/guides/troubleshooting.md`, and `README.md`. -- [ ] 6.1.5 Push branch and create Pull Request: `git push -u origin feature/add-debug-logs-specfact-home` then `gh pr create --base dev --title "feat: add debug logs under ~/.specfact/logs" --body "Closes #158. OpenSpec change: add-debug-logs-specfact-home."` (or use GitHub web UI). +- [x] 6.1.5 Push branch and create Pull Request: `git push -u origin feature/add-debug-logs-specfact-home` then `gh pr create --base dev --title "feat: add debug logs under ~/.specfact/logs" --body "Closes #158. OpenSpec change: add-debug-logs-specfact-home."` (or use GitHub web UI). diff --git a/openspec/specs/debug-logging/spec.md b/openspec/specs/debug-logging/spec.md new file mode 100644 index 0000000..66bacf2 --- /dev/null +++ b/openspec/specs/debug-logging/spec.md @@ -0,0 +1,131 @@ +# debug-logging Specification + +## Purpose +TBD - created by archiving change add-debug-logs-specfact-home. Update Purpose after archive. +## Requirements +### Requirement: User-level debug log directory + +The system SHALL provide a user-level directory for debug logs when debug mode is enabled. + +#### Scenario: Resolve ~/.specfact/logs + +- **GIVEN** debug mode may be enabled +- **WHEN** `get_specfact_home_logs_dir()` is called +- **THEN** returns path equivalent to `os.path.expanduser("~/.specfact/logs")` +- **AND** creates the directory with `os.makedirs(..., mode=0o755, exist_ok=True)` on first use + +#### Scenario: No directory when debug is off + +- **GIVEN** debug mode is disabled +- **WHEN** no debug log has been written in this run +- **THEN** `~/.specfact/logs` is not required to exist +- **AND** `get_specfact_home_logs_dir()` may still return the path for callers that need it + +### Requirement: Debug output routing + +The system SHALL route debug output to both console and a debug log file when debug mode is enabled. + +#### Scenario: debug_print writes to console and file when debug on + +- **GIVEN** debug mode is enabled and debug log file is initialized +- **WHEN** `debug_print(...)` is called +- **THEN** output is written to the configured Rich console (current behavior) +- **AND** the same content is appended to the debug log file under `~/.specfact/logs` + +#### Scenario: debug_print console-only when debug off + +- **GIVEN** debug mode is disabled +- **WHEN** `debug_print(...)` is called +- **THEN** no output is produced (current behavior) +- **AND** no debug log file is written + +### Requirement: Structured operation metadata + +The system SHALL support logging structured operation metadata when debug mode is enabled. + +#### Scenario: debug_log_operation no-op when debug off + +- **GIVEN** debug mode is disabled +- **WHEN** `debug_log_operation(operation=..., target=..., status=..., error=...)` is called +- **THEN** no log file write occurs +- **AND** no console output is produced + +#### Scenario: debug_log_operation writes metadata when debug on + +- **GIVEN** debug mode is enabled and debug log file is initialized +- **WHEN** `debug_log_operation(operation="api_request", target=url_redacted, status=200, error=None)` is called +- **THEN** a structured log line (or block) is written to the debug log file +- **AND** the line includes operation, target, status, and optionally error and extra fields +- **AND** sensitive values in target or extra are redacted (e.g. via LoggerSetup.redact_secrets) + +#### Scenario: Adapters log API metadata when debug on + +- **GIVEN** debug mode is enabled +- **WHEN** an adapter performs an API request (e.g. ADO WIQL, Work Items PATCH, GitHub REST) +- **THEN** the adapter logs operation metadata (operation type, URL redacted, method, status code) +- **AND** on failure, logs error snippet or response body (redacted) +- **AND** does not log full request/response bodies that may contain secrets + +### Requirement: Debug log standard (consistent pattern for anomaly analysis and bug reports) + +The system SHALL apply a consistent debug log pattern for every significant operation when debug mode is enabled, so that logs support anomaly analysis, unexpected error/failure diagnosis, reporting, and bug reports (production-tool quality). + +#### Scenario: Every significant operation has started, progress, and outcome + +- **GIVEN** debug mode is enabled +- **WHEN** a significant operation is performed (auth flow, file I/O, API call, template resolution, or any operation that can fail or affect behavior) +- **THEN** the implementation logs at least: **started/prepared** (once at begin), **attempt** (for each distinct step if multi-step), and **outcome** (exactly once: success with reason/method/cache or failed with error and reason) +- **AND** no operation is represented by only a single INFO-style line without outcome and reason +- **AND** structured lines include operation, target (redacted), status, and when applicable error, extra (payload/response/reason sanitized), caller + +#### Scenario: Reference implementation + +- **GIVEN** the auth azure-devops flow +- **WHEN** debug mode is enabled and the user runs the OAuth flow +- **THEN** the debug log contains: started → cache_prepared → attempt (interactive_browser) → success or fallback (with reason) → attempt (device_code) → success or failed (with error/reason) → success (token_stored with method/cache) +- **AND** a reader can determine from the log alone whether the flow succeeded or failed and why + +### Requirement: Debug log context (timestamp, caller, file/API details) + +The system SHALL include context in every debug log line when debug mode is enabled. + +#### Scenario: Timestamp on every line + +- **GIVEN** debug mode is enabled and debug log file is initialized +- **WHEN** any line is written to the debug log file (via debug_print or debug_log_operation) +- **THEN** the line is prefixed with a timestamp (e.g. `%(asctime)s | %(message)s` with datefmt `%Y-%m-%d %H:%M:%S`) + +#### Scenario: Caller (module/method) in structured lines + +- **GIVEN** debug mode is enabled +- **WHEN** `debug_log_operation(..., caller=...)` is called with a caller string (e.g. `module:function`) +- **THEN** the structured log line includes the caller in the payload +- **AND** call sites may infer caller via inspect or pass explicitly + +#### Scenario: File operations log prepared / finished / failed + +- **GIVEN** debug mode is enabled +- **WHEN** a command or adapter performs file IO (read/write) +- **THEN** it logs operation metadata with status prepared/started before the operation +- **AND** logs again with status finished or failed and error/reason when applicable +- **AND** target is the path (redacted if sensitive); extra may include size, mime, etc. + +#### Scenario: API operations log operation, URL, payload (sanitized), response, status, error, reason + +- **GIVEN** debug mode is enabled +- **WHEN** an adapter performs an API request +- **THEN** it logs operation metadata with operation type, target (URL redacted), status (HTTP or success/failure) +- **AND** extra includes payload (sanitized via LoggerSetup.redact_secrets), response (sanitized), and reason when applicable +- **AND** on failure, error and reason are included + +### Requirement: Backward compatibility + +The system SHALL preserve existing behavior when debug mode is disabled. + +#### Scenario: get_runtime_logs_dir unchanged + +- **GIVEN** any mode +- **WHEN** `get_runtime_logs_dir()` is called +- **THEN** returns the same path as before (repo-relative logs or /app/logs in Docker) +- **AND** behavior of LoggerSetup and existing loggers is unchanged +