diff --git a/CHANGELOG.md b/CHANGELOG.md index 2aa3ac98..57a52734 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,22 @@ All notable changes to this project will be documented in this file. **Important:** Changes need to be documented below this block as this is the header section. Each section should be separated by a horizontal rule. Newer changelog entries need to be added on top of prior ones to keep the history chronological with most recent changes first. +--- + +## [0.40.3] - 2026-03-09 + +### Changed + +- Improved `specfact module upgrade` success output so multi-module upgrades print one module per line with explicit `old -> new` version transitions. +- Updated contributor/testing docs to document the command-package runtime audit procedure and the normal-output vs `--debug` diagnostics policy. + +### Fixed + +- `specfact backlog map-fields` no longer blocks on non-mappable built-in required ADO hierarchy identifiers such as `System.IterationId` and `System.AreaId`. +- `specfact backlog map-fields` now reports incremental metadata-fetch progress after work item type selection instead of appearing stalled during follow-up field lookups. +- Shared bridge/registry logger diagnostics no longer leak raw log-formatted lines into normal console output when `--debug` is disabled. +- Successful bundled module upgrades no longer emit routine `dependency already satisfied` notices as warnings. + --- ## [0.40.2] - 2026-03-06 diff --git a/docs/reference/debug-logging.md b/docs/reference/debug-logging.md index e99044c8..0063a798 100644 --- a/docs/reference/debug-logging.md +++ b/docs/reference/debug-logging.md @@ -9,6 +9,20 @@ permalink: /debug-logging/ When you run SpecFact CLI with the global `--debug` flag, the CLI writes debug output to your **console** and to a **rotating log file** under your user directory. This helps diagnose I/O, API, and template issues without cluttering normal output. +## Normal Output vs Debug Output + +Normal command runs are expected to stay quiet unless there is actionable user work to do. + +Without `--debug`: + +- Internal module-discovery traces stay hidden. +- Partial protocol-compliance diagnostics stay hidden. +- Expected command ownership overlap between shipped core and official bundles stays hidden. +- Routine bundled-upgrade notices such as "dependency already satisfied" stay informational, not warning-level. +- Actionable security, integrity, trust, or real scope-conflict warnings still remain visible. + +Use `--debug` when you need to inspect discovery behavior, integrity fallback details, or the exact sequence of backend calls behind a long-running command. + ## For Users ### Enabling Debug Mode @@ -60,7 +74,9 @@ When `--debug` is on, the CLI logs: |----------|---------------------------------------------| | **auth azure-devops** | Start, success (PAT or OAuth), or error; key steps (OAuth flow, device code) when `--debug` is on. | | **init** | Template resolution: paths tried, success/failure, fallbacks (e.g. development path, package path, `importlib` fallbacks). | +| **module discovery / installer** | Discovery roots, canonical user-root deduplication, integrity fallback details, bundle dependency checks, and cached-marketplace fallbacks. | | **backlog refine** | File read for import: path, success/error (e.g. `--import-from-tmp`). File write for export: path, success/error (e.g. `--export-to-tmp`). | +| **backlog map-fields** | Selected work item type, metadata-fetch progress, and follow-up field/picklist resolution steps. | | **Azure DevOps adapter** | WIQL request (redacted URL, method, status); Work Items GET (redacted URL, status); Work Items PATCH (redacted URL, status). On PATCH failure: structured log with `operation=ado_patch`, `status=failed`, and `extra` containing `response_body` (redacted snippet of ADO error payload) and `patch_paths` (JSON Patch paths attempted). | | **GitHub adapter** | API request/response (redacted URL, method, status); on failure, redacted error snippet. | @@ -91,6 +107,7 @@ When `--debug` is on, the CLI logs: 2. Reproduce the issue, then open `~/.specfact/logs/specfact-debug.log`. 3. Look for: - **template_resolution** – Where `init` looked for templates and whether it succeeded. + - **module discovery / installer** – Why a module was discovered, skipped, deduplicated, verified, or reused. - **file_read** / **file_write** – Paths and success/error for backlog export/import. - **ado_wiql**, **ado_get**, **ado_patch** – ADO API calls (URLs redacted, status/error present). - **api_request** – GitHub (or other) API calls with status and optional error. @@ -118,6 +135,16 @@ To analyze an ADO API error: 4. In that line, use `extra.response_body` to see the server’s error text and `extra.patch_paths` to see which field paths were attempted. 5. If the error is about a missing or invalid field (e.g. custom process template), update [custom field mapping](../guides/custom-field-mapping.md) (e.g. `.specfact/templates/backlog/field_mappings/ado_custom.yaml`) or see [Azure DevOps Issues](../guides/troubleshooting.md#azure-devops-issues) in Troubleshooting. +### Interpreting Long `backlog map-fields` Runs + +`specfact backlog map-fields` now emits user-facing progress during the post-selection metadata fetch for the chosen ADO work item type. + +- The first status line tells you which work item type is being resolved. +- Follow-up `N/M` lines show which field metadata lookup is currently pending. +- Built-in ADO hierarchy identifiers such as `System.IterationId` and `System.AreaId` are system-managed and are not expected to be mapped interactively. + +If the command still appears stalled, rerun with `--debug` and inspect `~/.specfact/logs/specfact-debug.log` for the last field or API call reached. + --- ## For Developers diff --git a/docs/technical/testing.md b/docs/technical/testing.md index ad13d911..58dd92ed 100644 --- a/docs/technical/testing.md +++ b/docs/technical/testing.md @@ -55,6 +55,53 @@ hatch test --cover -v tests/integration/test_directory_structure.py::TestDirecto hatch test --cover -v tests/integration/test_directory_structure.py::TestDirectoryStructure::test_ensure_structure_creates_directories ``` +### Release Runtime Validation + +Before cutting or approving a release, run the command-package runtime audit against the shipped core plus official bundles. This complements unit and contract coverage by checking the command surface users actually invoke. + +Recommended order: + +```bash +# Core and bundle command-surface audit +python -m pytest tests/unit/validation/test_command_audit.py tests/integration/test_command_package_runtime_validation.py -q + +# Registry/discovery noise regressions +python -m pytest tests/unit/registry/test_module_discovery.py tests/unit/specfact_cli/registry/test_module_packages.py tests/unit/registry/test_module_installer.py -q + +# Backlog runtime regressions that depend on the split core + bundle architecture +hatch run pytest modules/backlog-core/tests/unit/test_add_command.py tests/unit/adapters/test_ado_backlog_adapter.py -q +``` + +What this audit is expected to prove: + +- Core commands (`specfact`, `init`, `module`, `upgrade`) stay usable before bundle installation. +- Official bundle roots (`project`, `spec`, `code`, `backlog`, `govern`) and their audited leaf commands are still registered. +- Normal command output stays clean: no duplicate-module chatter, protocol-compliance chatter, or expected-overlap warnings without `--debug`. +- Backlog split-runtime flows still work end to end, including `backlog refine ado`, `backlog map-fields`, and `backlog add`. + +For backlog marketplace-bundle regressions that live in the sibling modules repo, run the matching bundle tests from `../specfact-cli-modules` as part of the same release check: + +```bash +cd ../specfact-cli-modules +HATCH_DATA_DIR=/tmp/hatch-data HATCH_CACHE_DIR=/tmp/hatch-cache VIRTUALENV_OVERRIDE_APP_DATA=/tmp/virtualenv-appdata \ + hatch run pytest tests/unit/specfact_backlog/test_map_fields_command.py tests/unit/specfact_backlog/test_refine_adapter_contract.py -q +``` + +### Quality Gate Order + +For behavior changes, keep the local quality gates in this order: + +```bash +hatch run format +hatch run type-check +hatch run lint +hatch run yaml-lint +hatch run contract-test +hatch run smart-test +``` + +If the change affects bundled command packaging, module discovery, or backlog split-runtime behavior, include the runtime-audit tests above before sign-off. + ### Contract Testing (Brownfield & Greenfield) ```bash @@ -759,6 +806,10 @@ def test_with_fixtures(tmp_repo, sample_plan): ## Best Practices +- Add focused regression tests for any user-visible runtime noise. Clean non-debug output is a compatibility guarantee, not cosmetic polish. +- Prefer targeted runtime-audit coverage for command registration, module discovery, bundled upgrade flows, and split core/bundle backlog paths. +- When a command intentionally performs a long backend fetch, assert observable progress output so interactive runs do not appear hung. + ### 1. Test Isolation Ensure tests don't depend on each other or external state: diff --git a/openspec/CHANGE_ORDER.md b/openspec/CHANGE_ORDER.md index 0804abb1..6717077f 100644 --- a/openspec/CHANGE_ORDER.md +++ b/openspec/CHANGE_ORDER.md @@ -235,7 +235,7 @@ These are derived extensions of the same 2026-02-15 plan and are required to ope | cli-val | 04 | cli-val-04-acceptance-test-runner | [#282](https://github.com/nold-ai/specfact-cli/issues/282) | #279, #281 | | cli-val | 05 | cli-val-05-ci-integration | [#283](https://github.com/nold-ai/specfact-cli/issues/283) | #280, #282 | | cli-val | 06 | cli-val-06-copilot-test-generation | [#284](https://github.com/nold-ai/specfact-cli/issues/284) | #279 (soft: #283) | -| cli-val | 07 | cli-val-07-command-package-runtime-validation | TBD | marketplace-02 ✅; backlog-core-05 ✅; module-migration-08 ✅ | +| cli-val | 07 | cli-val-07-command-package-runtime-validation | implemented 2026-03-09 (archive pending) | marketplace-02 ✅; backlog-core-05 ✅; module-migration-08 ✅ | ### Integration governance and proof (architecture integration plan, 2026-02-15) diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/CHANGE_VALIDATION.md b/openspec/changes/cli-val-07-command-package-runtime-validation/CHANGE_VALIDATION.md index bc167589..98a03b32 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/CHANGE_VALIDATION.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/CHANGE_VALIDATION.md @@ -5,6 +5,40 @@ - **Strict command:** `openspec validate cli-val-07-command-package-runtime-validation --strict` - **Result:** PASS +## Implementation Finalization Update + +- **Updated on (UTC):** 2026-03-09T21:23:21Z +- **Implementation status:** Implemented, archive pending +- **Finalized scope additions during implementation:** + - `backlog map-fields` now ignores non-mappable built-in required ADO hierarchy identifiers (`System.IterationId`, `System.AreaId`) + - `backlog map-fields` now emits incremental `N/M` metadata-fetch progress after work item type selection + - shared bridge logger diagnostics are hidden from normal console output unless `--debug` is enabled + - `specfact module upgrade` now reports each upgraded module on its own line with `old -> new` versions +- **Evidence updated:** `TDD_EVIDENCE.md` contains failing/passing runs for backlog mapping, bundled-upgrade warning severity, logger-output leakage, and module-upgrade output formatting +- **Docs updated:** `docs/technical/testing.md` and `docs/reference/debug-logging.md` +- **Version release target:** `0.40.3` + +## Final Validation Evidence + +- Focused regressions passed: + - `python -m pytest tests/unit/test_runtime.py -q -k bridge_logger_stays_off_console_when_debug_disabled` + - `python -m pytest tests/unit/registry/test_module_installer.py -q -k satisfied_dependencies_without_warning` + - `python -m pytest tests/unit/modules/module_registry/test_commands.py -q -k "upgrade_command or upgrade_without_module_name_upgrades_all_marketplace or one_line_per_module_with_versions"` + - `cd /home/dom/git/nold-ai/specfact-cli-modules && HATCH_DATA_DIR=/tmp/hatch-data HATCH_CACHE_DIR=/tmp/hatch-cache VIRTUALENV_OVERRIDE_APP_DATA=/tmp/virtualenv-appdata hatch run pytest tests/unit/specfact_backlog/test_map_fields_command.py -q -k "reports_progress_for_selected_work_item_type_metadata or interactive_ignores_builtin_required_hierarchy_ids"` +- Local quality gates passed during implementation: + - `hatch run format` + - `hatch run type-check` + - `hatch run lint` + - `hatch run yaml-lint` + - `hatch run contract-test` + - `hatch run smart-test` + +## Final Assessment + +- Runtime-validation scope is now implemented and evidenced. +- Normal non-debug output is cleaner and user-directed, while actionable warnings remain visible through explicit formatting paths. +- The change is ready for commit/PR/archive workflow steps. + ## Scope Summary - **New capabilities:** `command-package-runtime-validation` diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/TDD_EVIDENCE.md b/openspec/changes/cli-val-07-command-package-runtime-validation/TDD_EVIDENCE.md index a0b37446..74e514d0 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/TDD_EVIDENCE.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/TDD_EVIDENCE.md @@ -77,3 +77,87 @@ - The backlog marketplace bundle now shares the core backlog adapter contract, so `refine ado` no longer fails on the adapter type check. - `backlog map-fields` now emits an explicit status line before fetching required-field and picklist metadata for the selected work item type, eliminating the silent post-selection stall. + +## Additional pre-implementation failing run (2026-03-09 regressions, modules repo) + +- **Timestamp (UTC):** 2026-03-09T21:05:54Z +- **Command:** `cd /home/dom/git/nold-ai/specfact-cli-modules && HATCH_DATA_DIR=/tmp/hatch-data HATCH_CACHE_DIR=/tmp/hatch-cache VIRTUALENV_OVERRIDE_APP_DATA=/tmp/virtualenv-appdata hatch run pytest tests/unit/specfact_backlog/test_map_fields_command.py -q -k "reports_progress_for_selected_work_item_type_metadata or interactive_ignores_builtin_required_hierarchy_ids"` +- **Result:** FAIL + +### Failure summary + +- `tests/unit/specfact_backlog/test_map_fields_command.py::test_map_fields_reports_progress_for_selected_work_item_type_metadata` failed because `map-fields` still prints only the initial selected-type status line and never reports incremental follow-up field-metadata progress. +- `tests/unit/specfact_backlog/test_map_fields_command.py::test_map_fields_interactive_ignores_builtin_required_hierarchy_ids` failed before the prompt flow could complete because the command still treats `System.IterationId` and `System.AreaId` like mappable required fields and attempts provider-field fetches for them. + +## Additional pre-implementation failing run (2026-03-09 regressions, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:05:54Z +- **Command:** `python -m pytest tests/unit/registry/test_module_installer.py -q -k satisfied_dependencies_without_warning` +- **Result:** FAIL + +### Failure summary + +- `tests/unit/registry/test_module_installer.py::test_install_module_logs_satisfied_dependencies_without_warning` failed because `install_module()` still logs `Dependency ... already satisfied` through `logger.warning(...)` during a successful bundled upgrade path. + +## Additional post-implementation passing run (2026-03-09 regressions, modules repo) + +- **Timestamp (UTC):** 2026-03-09T21:07:05Z +- **Command:** `cd /home/dom/git/nold-ai/specfact-cli-modules && HATCH_DATA_DIR=/tmp/hatch-data HATCH_CACHE_DIR=/tmp/hatch-cache VIRTUALENV_OVERRIDE_APP_DATA=/tmp/virtualenv-appdata hatch run pytest tests/unit/specfact_backlog/test_map_fields_command.py -q -k "reports_progress_for_selected_work_item_type_metadata or interactive_ignores_builtin_required_hierarchy_ids"` +- **Result:** PASS + +### Passing summary + +- `backlog map-fields` now reports incremental `Fetching field metadata details N/M` progress while resolving follow-up metadata requests for the selected ADO work item type. +- The interactive mapping flow now skips non-mappable built-in required hierarchy identifiers such as `System.IterationId` and `System.AreaId`, so successful runs are gated only by actually mappable required fields. + +## Additional post-implementation passing run (2026-03-09 regressions, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:07:05Z +- **Command:** `python -m pytest tests/unit/registry/test_module_installer.py -q -k satisfied_dependencies_without_warning` +- **Result:** PASS + +### Passing summary + +- Successful bundled installs and upgrades now keep already-satisfied dependency notices out of warning severity while preserving the message as non-warning runtime context. + +## Additional pre-implementation failing run (2026-03-09 logger-output regression, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:19:19Z +- **Command:** `python -m pytest tests/unit/test_runtime.py -q -k bridge_logger_stays_off_console_when_debug_disabled` +- **Result:** FAIL + +### Failure summary + +- `tests/unit/test_runtime.py::TestBridgeLoggerOutput::test_bridge_logger_stays_off_console_when_debug_disabled` failed because the shared bridge logger still streamed raw `name | timestamp | level | message` lines to the console even when debug mode was disabled. + +## Additional post-implementation passing run (2026-03-09 logger-output regression, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:20:09Z +- **Command:** `python -m pytest tests/unit/test_runtime.py -q -k bridge_logger_stays_off_console_when_debug_disabled` +- **Result:** PASS + +### Passing summary + +- Shared bridge logger diagnostics no longer leak raw log-formatted lines to the normal console when `--debug` is off. +- Explicit user-facing warnings still remain the responsibility of formatted prompt helpers rather than raw logger output. + +## Additional pre-implementation failing run (2026-03-09 module-upgrade output regression, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:20:09Z +- **Command:** `python -m pytest tests/unit/modules/module_registry/test_commands.py -q -k one_line_per_module_with_versions` +- **Result:** FAIL + +### Failure summary + +- `tests/unit/modules/module_registry/test_commands.py::test_upgrade_without_module_name_reports_one_line_per_module_with_versions` failed because `specfact module upgrade` still reported upgraded modules as one comma-joined line and did not include `old -> new` version transitions. + +## Additional post-implementation passing run (2026-03-09 module-upgrade output regression, core repo) + +- **Timestamp (UTC):** 2026-03-09T21:23:21Z +- **Command:** `python -m pytest tests/unit/modules/module_registry/test_commands.py -q -k "upgrade_command or upgrade_without_module_name_upgrades_all_marketplace or one_line_per_module_with_versions"` +- **Result:** PASS + +### Passing summary + +- `specfact module upgrade` now prints upgraded modules one per line instead of collapsing them into a single comma-joined summary. +- Each upgraded module line now includes the resolved version transition in `old -> new` form, sourced from the post-install manifest written by the upgrade. diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/backlog-runtime-compatibility/spec.md b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/backlog-runtime-compatibility/spec.md index 2a941819..c28a1bf4 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/backlog-runtime-compatibility/spec.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/backlog-runtime-compatibility/spec.md @@ -28,8 +28,17 @@ The system SHALL keep the interactive `backlog map-fields` flow responsive and o - **GIVEN** the user selected an ADO work item type during `specfact backlog map-fields` - **WHEN** the command fetches work-item-type field metadata and follow-up allowed-value or picklist data - **THEN** the CLI emits progress or status text before the next prompt gap +- **AND** when multiple metadata items must be resolved the status output shows incremental progress for the pending item count - **AND** the command does not appear to stop silently after the work item type selection. +#### Scenario: Built-in required hierarchy identifiers do not block successful mapping + +- **GIVEN** the selected ADO work item type marks built-in hierarchy identifiers such as `System.IterationId` or `System.AreaId` as required +- **AND** those fields are system-managed and are not valid interactive mapping targets +- **WHEN** `specfact backlog map-fields` validates the selected-type required-field metadata +- **THEN** the command does not require explicit user mappings for those built-in identifiers +- **AND** it still succeeds when every actually mappable required field is resolved. + #### Scenario: Selected work item type metadata is persisted for later create-time validation - **GIVEN** `specfact backlog map-fields` completes successfully for a selected ADO work item type diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/command-package-runtime-validation/spec.md b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/command-package-runtime-validation/spec.md index 5009abf7..fbbe5ca3 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/command-package-runtime-validation/spec.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/command-package-runtime-validation/spec.md @@ -90,3 +90,10 @@ The system SHALL emit a report that maps findings to the responsible package, co - **THEN** each failure lists the owning package, command path, phase, exit code, and observed stdout/stderr summary - **AND** startup-noise failures are distinguishable from functional command failures - **AND** the report can be used to drive targeted fixes in core or `specfact-cli-modules`. + +#### Scenario: Upgrade command output stays readable for multiple modules + +- **GIVEN** `specfact module upgrade` upgrades more than one marketplace module in a single run +- **WHEN** the command reports success +- **THEN** it prints one line per upgraded module rather than a single comma-joined list +- **AND** each line includes the module id plus the previous and resulting version in `old -> new` form. diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/debug-logging/spec.md b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/debug-logging/spec.md index da05dfdd..8f0df63d 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/specs/debug-logging/spec.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/specs/debug-logging/spec.md @@ -25,3 +25,18 @@ The system SHALL keep internal module-discovery diagnostics out of normal comman - **WHEN** module discovery encounters a security, trust, integrity, or real scope-precedence problem that requires user action - **THEN** the CLI still emits an actionable warning - **AND** the warning text explains the remediation instead of exposing raw internal diagnostics. + +#### Scenario: Routine bundled dependency satisfaction stays non-warning + +- **GIVEN** `--debug` is not enabled +- **AND** a bundled module upgrade sees that a declared bundled dependency is already installed at the required version +- **WHEN** the upgrade completes without conflict, trust, or integrity problems +- **THEN** normal output does not emit a warning for that already-satisfied dependency +- **AND** any optional trace for the satisfied dependency is routed to debug or informational channels instead. + +#### Scenario: Bridge logger lines stay out of normal console output + +- **GIVEN** `--debug` is not enabled +- **WHEN** internal bridge or registry code records non-actionable informational or warning diagnostics through the shared logger +- **THEN** those raw logger lines do not appear in the user's console output +- **AND** only explicitly formatted user-facing warnings remain visible when the user must take action. diff --git a/openspec/changes/cli-val-07-command-package-runtime-validation/tasks.md b/openspec/changes/cli-val-07-command-package-runtime-validation/tasks.md index 5328b825..6c4bf08a 100644 --- a/openspec/changes/cli-val-07-command-package-runtime-validation/tasks.md +++ b/openspec/changes/cli-val-07-command-package-runtime-validation/tasks.md @@ -28,6 +28,10 @@ Per `openspec/config.yaml`, tests before code for any behavior-changing task. Or - [x] 3.6 Add a failing regression test for `backlog map-fields` showing explicit progress after work-item-type selection and persisting required-field/picklist metadata for the selected type. - [x] 3.7 Add failing regression coverage for `backlog add` consuming saved required-field and allowed-values metadata, including `--custom-field` validation and forwarding. - [x] 3.8 Capture the new pre-implementation failing runs and summaries in `TDD_EVIDENCE.md`. +- [x] 3.9 Add a failing regression test proving `backlog map-fields` ignores built-in required identifiers such as `System.IterationId` and `System.AreaId`, while reporting incremental metadata-fetch progress. +- [x] 3.10 Add a failing regression test proving bundled module upgrades do not log routine already-satisfied dependencies as warnings during successful upgrade flows. +- [x] 3.11 Add a failing regression test proving bridge logger diagnostics do not leak raw log-formatted lines to the console when `--debug` is off. +- [x] 3.12 Add a failing regression test proving `specfact module upgrade` reports one upgraded module per line with `old -> new` versions. ## 4. Implement runtime-audit and output-cleanup fixes @@ -40,6 +44,12 @@ Per `openspec/config.yaml`, tests before code for any behavior-changing task. Or - [x] 4.7 Make `backlog map-fields` surface progress while fetching required-field and picklist metadata after work-item-type selection. - [x] 4.8 Extend `backlog add` to consume saved required-field and allowed-values metadata, expose repeatable `--custom-field`, and fail with actionable guidance on missing or invalid required custom fields. - [x] 4.9 Re-run the new backlog validation tests and record the passing post-implementation evidence in `TDD_EVIDENCE.md`. +- [x] 4.10 Exempt non-mappable built-in ADO hierarchy identifiers from required-field mapping failures, add incremental metadata-fetch status output, and demote already-satisfied bundled dependency upgrade messages out of warning severity. +- [x] 4.11 Re-run the new regression tests and record the failing/passing evidence in `TDD_EVIDENCE.md`. +- [x] 4.12 Keep shared bridge logger diagnostics off the normal console unless `--debug` is enabled, while preserving explicit user-facing warnings. +- [x] 4.13 Re-run the logger-output regression tests and record the failing/passing evidence in `TDD_EVIDENCE.md`. +- [x] 4.14 Make `specfact module upgrade` report per-module `old -> new` versions on separate lines for multi-module upgrades. +- [x] 4.15 Re-run the module-upgrade output regression test and record the failing/passing evidence in `TDD_EVIDENCE.md`. ## 5. Cover each package in logical order @@ -53,22 +63,22 @@ Per `openspec/config.yaml`, tests before code for any behavior-changing task. Or ## 6. Documentation and release-validation guidance -- [ ] 6.1 Update docs for contributor/release workflows with the command-package audit procedure and command coverage expectations. -- [ ] 6.2 Update docs/reference guidance for clean normal output versus `--debug` diagnostics if command-output behavior changes. +- [x] 6.1 Update docs for contributor/release workflows with the command-package audit procedure and command coverage expectations. +- [x] 6.2 Update docs/reference guidance for clean normal output versus `--debug` diagnostics if command-output behavior changes. ## 7. Quality gates - [x] 7.1 `hatch run format` - [x] 7.2 `hatch run type-check` -- [ ] 7.3 `hatch run lint` +- [x] 7.3 `hatch run lint` - [x] 7.4 `hatch run yaml-lint` -- [ ] 7.5 `hatch run contract-test` -- [ ] 7.6 `hatch run smart-test` +- [x] 7.5 `hatch run contract-test` +- [x] 7.6 `hatch run smart-test` - [x] 7.7 `openspec validate cli-val-07-command-package-runtime-validation --strict` ## 8. Delivery -- [ ] 8.1 Update `openspec/CHANGE_ORDER.md` and `CHANGE_VALIDATION.md` with final implementation status and validation evidence. +- [x] 8.1 Update `openspec/CHANGE_ORDER.md` and `CHANGE_VALIDATION.md` with final implementation status and validation evidence. - [ ] 8.2 Stage and commit using a conventional commit message for this validation/fix scope. - [ ] 8.3 Push the branch and open a PR against `dev`. diff --git a/pyproject.toml b/pyproject.toml index aa001623..0974e4fe 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "hatchling.build" [project] name = "specfact-cli" -version = "0.40.2" +version = "0.40.3" description = "The swiss knife CLI for agile DevOps teams. Keep backlog, specs, tests, and code in sync with validation and contract enforcement for new projects and long-lived codebases." readme = "README.md" requires-python = ">=3.11" diff --git a/setup.py b/setup.py index 657597a7..7456aa10 100644 --- a/setup.py +++ b/setup.py @@ -7,7 +7,7 @@ if __name__ == "__main__": _setup = setup( name="specfact-cli", - version="0.40.2", + version="0.40.3", description=( "The swiss knife CLI for agile DevOps teams. Keep backlog, specs, tests, and code in sync with " "validation and contract enforcement for new projects and long-lived codebases." diff --git a/src/__init__.py b/src/__init__.py index fb8eb3a1..c7dceefd 100644 --- a/src/__init__.py +++ b/src/__init__.py @@ -3,4 +3,4 @@ """ # Package version: keep in sync with pyproject.toml, setup.py, src/specfact_cli/__init__.py -__version__ = "0.40.2" +__version__ = "0.40.3" diff --git a/src/specfact_cli/__init__.py b/src/specfact_cli/__init__.py index 01febbf9..5983cb45 100644 --- a/src/specfact_cli/__init__.py +++ b/src/specfact_cli/__init__.py @@ -42,6 +42,6 @@ def _bootstrap_bundle_paths() -> None: _bootstrap_bundle_paths() -__version__ = "0.40.2" +__version__ = "0.40.3" __all__ = ["__version__"] diff --git a/src/specfact_cli/common/logger_setup.py b/src/specfact_cli/common/logger_setup.py index a84d5039..9bfe1af4 100644 --- a/src/specfact_cli/common/logger_setup.py +++ b/src/specfact_cli/common/logger_setup.py @@ -396,6 +396,7 @@ def create_logger( use_rotating_file: bool = True, append_mode: bool = True, preserve_test_format: bool = False, + emit_to_console: bool = True, ) -> logging.Logger: """ Creates a new logger or returns an existing one with the specified configuration. @@ -513,15 +514,20 @@ def create_logger( with contextlib.suppress(Exception): logger.info("[LoggerSetup] File logger initialized: %s", log_file_path) else: - # If no log file is specified, set up a listener with a console handler + # If no log file is specified, stream to console only when explicitly requested. log_queue = Queue(-1) cls._log_queues[logger_name] = log_queue - console_handler = logging.StreamHandler(_safe_console_stream()) - console_handler.setFormatter(log_format) - console_handler.setLevel(level) + sink_handler: logging.Handler + if emit_to_console: + sink_handler = logging.StreamHandler(_safe_console_stream()) + sink_handler.setFormatter(log_format) + sink_handler.setLevel(level) + else: + sink_handler = logging.NullHandler() + sink_handler.setLevel(level) - listener = QueueListener(log_queue, console_handler, respect_handler_level=True) + listener = QueueListener(log_queue, sink_handler, respect_handler_level=True) listener.start() cls._log_listeners[logger_name] = listener diff --git a/src/specfact_cli/common/logging_utils.py b/src/specfact_cli/common/logging_utils.py index 88c58397..44bed0bb 100644 --- a/src/specfact_cli/common/logging_utils.py +++ b/src/specfact_cli/common/logging_utils.py @@ -38,4 +38,10 @@ def _try_common_logger(name: str, level: str) -> logging.Logger | None: from specfact_cli.common.logger_setup import LoggerSetup # type: ignore[import] except ImportError: return None - return LoggerSetup.create_logger(name, log_level=level) + try: + from specfact_cli.runtime import is_debug_mode # type: ignore[import] + + emit_to_console = is_debug_mode() + except ImportError: + emit_to_console = False + return LoggerSetup.create_logger(name, log_level=level, emit_to_console=emit_to_console) diff --git a/src/specfact_cli/modules/module_registry/module-package.yaml b/src/specfact_cli/modules/module_registry/module-package.yaml index 458a4df5..c023e489 100644 --- a/src/specfact_cli/modules/module_registry/module-package.yaml +++ b/src/specfact_cli/modules/module_registry/module-package.yaml @@ -1,5 +1,5 @@ name: module-registry -version: 0.1.9 +version: 0.1.10 commands: - module category: core @@ -17,5 +17,5 @@ publisher: description: 'Manage modules: search, list, show, install, and upgrade.' license: Apache-2.0 integrity: - checksum: sha256:d8d4103bfe44bc638fd5affa2734bbb063f9c86f2873055f745beca9ee0a9db3 - signature: OJtCXdfZfnLZhB543+ODtFRXgyYamZk6xrvLfHubE+kwU+jCPWaZDJ83YqheuR7kQlqMlRue5UZb3DbOu4pwBQ== + checksum: sha256:85e40c4c083982f0bab2bde2a27a08a4e6832fe6d93ae3d62c4659c138fd6295 + signature: INFP+nx7iPCqZPnGIwB39L6GpckB16+EqPwaPW/kwwBtlLBX9RaZ1DcMbhu5f6tPqjA9sETRMBtrQ5GiBbVfCQ== diff --git a/src/specfact_cli/modules/module_registry/src/commands.py b/src/specfact_cli/modules/module_registry/src/commands.py index 205b7402..ded2664f 100644 --- a/src/specfact_cli/modules/module_registry/src/commands.py +++ b/src/specfact_cli/modules/module_registry/src/commands.py @@ -7,6 +7,7 @@ from pathlib import Path import typer +import yaml from beartype import beartype from rich.console import Console from rich.table import Table @@ -39,6 +40,20 @@ console = Console() +def _read_installed_module_version(module_dir: Path) -> str: + """Read installed module version from its manifest, if available.""" + manifest_path = module_dir / "module-package.yaml" + if not manifest_path.exists(): + return "unknown" + try: + loaded = yaml.safe_load(manifest_path.read_text(encoding="utf-8")) + except Exception: + return "unknown" + if not isinstance(loaded, dict): + return "unknown" + return str(loaded.get("version", "unknown")) + + def _publisher_from_module_id(module_id: str) -> str: """Extract normalized publisher namespace from module id.""" return module_id.split("/", 1)[0].strip().lower() if "/" in module_id else "" @@ -803,19 +818,22 @@ def upgrade( # If module isn't discovered locally, still attempt marketplace install/upgrade by ID. target_ids = [prefixed] - upgraded: list[str] = [] + upgraded: list[tuple[str, str, str]] = [] failed: list[str] = [] for target in target_ids: try: module_id = target if "/" in target else f"specfact/{target}" - install_module(module_id, reinstall=True) - upgraded.append(module_id) + previous_version = str(by_id.get(target, {}).get("version", "unknown")) + installed_path = install_module(module_id, reinstall=True) + upgraded.append((module_id, previous_version, _read_installed_module_version(installed_path))) except Exception as exc: console.print(f"[red]Failed upgrading {target}: {exc}[/red]") failed.append(target) if upgraded: - console.print(f"[green]Upgraded[/green] {', '.join(upgraded)}") + console.print("[green]Upgraded:[/green]") + for module_id, previous_version, new_version in upgraded: + console.print(f" {module_id}: {previous_version} -> {new_version}") if failed: raise typer.Exit(1) diff --git a/src/specfact_cli/registry/module_installer.py b/src/specfact_cli/registry/module_installer.py index da5d5476..10051885 100644 --- a/src/specfact_cli/registry/module_installer.py +++ b/src/specfact_cli/registry/module_installer.py @@ -730,7 +730,7 @@ def install_module( dependency_manifest = target_root / dependency_name / "module-package.yaml" if dependency_manifest.exists(): dependency_version = _installed_dependency_version(dependency_manifest) - logger.warning( + logger.info( "Dependency %s already satisfied (version %s)", dependency_module_id, dependency_version ) continue diff --git a/tests/unit/modules/module_registry/test_commands.py b/tests/unit/modules/module_registry/test_commands.py index 0ee17594..14a254eb 100644 --- a/tests/unit/modules/module_registry/test_commands.py +++ b/tests/unit/modules/module_registry/test_commands.py @@ -1060,6 +1060,38 @@ def _install(module_id: str, version=None, reinstall: bool = False): assert "Upgraded" in result.stdout +def test_upgrade_without_module_name_reports_one_line_per_module_with_versions(monkeypatch, tmp_path: Path) -> None: + installed: list[str] = [] + + def _install(module_id: str, version=None, reinstall: bool = False): + installed.append(module_id) + module_dir = tmp_path / module_id.split("/")[-1] + module_dir.mkdir(parents=True, exist_ok=True) + new_version = "0.3.0" if module_id.endswith("backlog") else "0.5.0" + (module_dir / "module-package.yaml").write_text( + f"name: {module_id.split('/')[-1]}\nversion: '{new_version}'\ncommands: [{module_id.split('/')[-1]}]\n", + encoding="utf-8", + ) + return module_dir + + monkeypatch.setattr("specfact_cli.modules.module_registry.src.commands.install_module", _install) + monkeypatch.setattr( + "specfact_cli.modules.module_registry.src.commands.get_modules_with_state", + lambda: [ + {"id": "nold-ai/specfact-backlog", "version": "0.2.0", "enabled": True, "source": "marketplace"}, + {"id": "nold-ai/specfact-project", "version": "0.4.0", "enabled": True, "source": "marketplace"}, + ], + ) + + result = runner.invoke(app, ["upgrade"]) + + assert result.exit_code == 0 + assert installed == ["nold-ai/specfact-backlog", "nold-ai/specfact-project"] + assert "Upgraded" in result.stdout + assert "nold-ai/specfact-backlog: 0.2.0 -> 0.3.0" in result.stdout + assert "nold-ai/specfact-project: 0.4.0 -> 0.5.0" in result.stdout + + def test_upgrade_rejects_non_marketplace_source(monkeypatch) -> None: monkeypatch.setattr( "specfact_cli.modules.module_registry.src.commands.get_modules_with_state", diff --git a/tests/unit/registry/test_module_installer.py b/tests/unit/registry/test_module_installer.py index 4c94363c..3019012d 100644 --- a/tests/unit/registry/test_module_installer.py +++ b/tests/unit/registry/test_module_installer.py @@ -19,10 +19,15 @@ def _create_module_tarball( module_name: str, core_compatibility: str = ">=0.1.0,<1.0.0", module_version: str = "0.1.0", + bundle_dependencies: list[str] | None = None, ) -> Path: package_root = tmp_path / f"{module_name}-pkg" module_dir = package_root / module_name module_dir.mkdir(parents=True, exist_ok=True) + dependency_yaml = "" + if bundle_dependencies: + rendered_dependencies = ", ".join(f"'{dependency}'" for dependency in bundle_dependencies) + dependency_yaml = f"bundle_dependencies: [{rendered_dependencies}]\n" (module_dir / "module-package.yaml").write_text( f"name: {module_name}\n" f"version: '{module_version}'\n" @@ -30,6 +35,11 @@ def _create_module_tarball( f'core_compatibility: "{core_compatibility}"\n', encoding="utf-8", ) + if dependency_yaml: + (module_dir / "module-package.yaml").write_text( + (module_dir / "module-package.yaml").read_text(encoding="utf-8") + dependency_yaml, + encoding="utf-8", + ) (module_dir / "src").mkdir(parents=True, exist_ok=True) tarball = tmp_path / f"{module_name}.tar.gz" @@ -87,6 +97,42 @@ def _download(_module_id: str, version: str | None = None) -> Path: assert "version: '0.2.0'" in manifest +def test_install_module_logs_satisfied_dependencies_without_warning(monkeypatch, tmp_path: Path) -> None: + tarball = _create_module_tarball( + tmp_path, + "backlog", + bundle_dependencies=["nold-ai/specfact-project"], + ) + monkeypatch.setattr("specfact_cli.registry.module_installer.download_module", lambda *_args, **_kwargs: tarball) + monkeypatch.setattr("specfact_cli.registry.module_installer.verify_module_artifact", lambda *_args, **_kwargs: True) + monkeypatch.setattr( + "specfact_cli.registry.module_installer.ensure_publisher_trusted", lambda *_args, **_kwargs: None + ) + monkeypatch.setattr("specfact_cli.registry.module_installer.resolve_dependencies", lambda *_args, **_kwargs: None) + monkeypatch.setattr("specfact_cli.registry.module_installer.discover_all_modules", list) + + mock_logger = MagicMock() + monkeypatch.setattr(module_installer, "get_bridge_logger", lambda _name: mock_logger) + + install_root = tmp_path / "marketplace-modules" + dependency_dir = install_root / "specfact-project" + dependency_dir.mkdir(parents=True, exist_ok=True) + (dependency_dir / "module-package.yaml").write_text( + "name: specfact-project\nversion: '0.40.16'\ncommands: [project]\n", + encoding="utf-8", + ) + + installed = install_module("nold-ai/specfact-backlog", install_root=install_root, reinstall=True) + + assert installed.exists() + mock_logger.warning.assert_not_called() + mock_logger.info.assert_called_once_with( + "Dependency %s already satisfied (version %s)", + "nold-ai/specfact-project", + "0.40.16", + ) + + def test_install_module_rejects_archive_path_traversal(monkeypatch, tmp_path: Path) -> None: tarball = tmp_path / "unsafe.tar.gz" with tarfile.open(tarball, "w:gz") as archive: diff --git a/tests/unit/test_runtime.py b/tests/unit/test_runtime.py index e0282daf..9c8c2fbd 100644 --- a/tests/unit/test_runtime.py +++ b/tests/unit/test_runtime.py @@ -6,6 +6,7 @@ import os import re +from io import StringIO from pathlib import Path from unittest.mock import patch @@ -250,3 +251,27 @@ def test_debug_log_operation_writes_when_debug_on(self, tmp_path: Path) -> None: assert "api_request" in content assert "200" in content assert '"caller"' in content + + +class TestBridgeLoggerOutput: + """Test shared bridge logger console visibility rules.""" + + def test_bridge_logger_stays_off_console_when_debug_disabled(self, capsys) -> None: + """Shared bridge logger should not emit raw log lines to console in normal mode.""" + import specfact_cli.common.logger_setup as logger_setup_mod + from specfact_cli.common import get_bridge_logger + + logger_name = "test.bridge.normal-output" + existing_listener = logger_setup_mod.LoggerSetup._log_listeners.pop(logger_name, None) + if existing_listener is not None: + existing_listener.stop() + logger_setup_mod.LoggerSetup._active_loggers.pop(logger_name, None) + + fake_stream = StringIO() + set_debug_mode(False) + with patch("specfact_cli.common.logger_setup._safe_console_stream", return_value=fake_stream): + logger = get_bridge_logger(logger_name) + logger.warning("raw bridge diagnostic should stay hidden") + logger_setup_mod.LoggerSetup._log_listeners[logger_name].stop() + + assert "raw bridge diagnostic should stay hidden" not in fake_stream.getvalue() diff --git a/tests/unit/validators/test_bundle_dependency_install.py b/tests/unit/validators/test_bundle_dependency_install.py index 5d65220c..614780e8 100644 --- a/tests/unit/validators/test_bundle_dependency_install.py +++ b/tests/unit/validators/test_bundle_dependency_install.py @@ -144,8 +144,10 @@ def _download(module_id: str, version: str | None = None) -> Path: install_module("nold-ai/specfact-spec", install_root=install_root) assert calls == ["nold-ai/specfact-spec"] + info_messages = " ".join(str(call.args[0]) for call in mock_logger.info.call_args_list) warning_messages = " ".join(str(call.args[0]) for call in mock_logger.warning.call_args_list) - assert "already satisfied" in warning_messages + assert "already satisfied" in info_messages + assert "already satisfied" not in warning_messages def test_requested_bundle_install_aborts_when_dependency_install_fails(