fix: finalize cli runtime validation regressions

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

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

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:

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)
 

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`

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.

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

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.