[#70] feat(logging): add YAML-based file logging and key-path log coverage (#71)

### What changes were proposed in this pull request?

- Add `conf/logging_conf.yaml.template`: Python `dictConfig` YAML with
`console` (stderr) + `RotatingFileHandler` at
`./hypervisor-logs/hypervisor.log` (10 MB, 5 backups)
- Rewrite `_configure_logging()` in `__main__.py`: loads YAML from
config dir, auto-creates log directories, prints startup notice to
stderr before logger init; `--log-level` now overrides config-file level
instead of being the sole source
- Fill key-path log gaps:
- `protocol/dispatcher.py`: per-request `method`, `request_id`,
`status`, `duration_ms`
- `policy/enforcer.py`: WARNING on access-denied, DEBUG on
access-granted and role resolution
- `handlers/ping.py`, `handlers/initialize.py`, `handlers/execute.py`:
lifecycle logs
- `manifest/yaml_provider.py`: `backends=N, resources=N` counts on load
- `backends/rdbms/backend.py`: query completion with timing and row
count
- Update README with Logging Configuration section

### Why are the changes needed?

Fix: #70

The server had no file logging and several critical paths produced no
log output, making it difficult to diagnose issues in deployed
environments.

### Does this PR introduce _any_ user-facing change?

- New CLI default behavior: logs are now written to
`./hypervisor-logs/hypervisor.log` (relative to CWD) in addition to
stderr. The directory is created automatically.
- `--log-level` now overrides the config-file level rather than being
the sole source of truth.
- New file `conf/logging_conf.yaml.template` can be copied to the config
directory as `logging_conf.yaml` to customise log format, rotation, and
level.

### How was this patch tested?

- All 624 unit tests pass (`uv run python -m unittest discover -s tests
-v`)
- `uv run black . && uv run ruff check . && uv run mypy` — all clean
- Live server smoke test with localfs backend: confirmed
`hypervisor-logs/hypervisor.log` is created in CWD, stdout contains only
JSON-RPC responses, all key-path logs appear in both stderr and file
(startup, manifest load, backend connect, request dispatch with timing,
policy role resolution, execute with row count, graceful shutdown)

---------

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Author: mchades

README.md

@@ -70,11 +70,41 @@ The server starts in stdio mode, reading JSON-RPC requests from stdin and writin
 python -m adp_hypervisor --config <path> [--log-level LEVEL] [--transport TYPE]
 ```
 
-| Option        | Default  | Description                                                            |
-|:--------------|:---------|:-----------------------------------------------------------------------|
-| `--config`    | Required | Path to manifest directory (physical.yaml, semantic.yaml, policy.yaml) |
-| `--log-level` | `INFO`   | Logging level: DEBUG, INFO, WARNING, ERROR, CRITICAL                   |
-| `--transport` | `stdio`  | Transport type: `stdio` (HTTP planned for future release)              |
+| Option        | Default            | Description                                                            |
+|:--------------|:-------------------|:-----------------------------------------------------------------------|
+| `--config`    | Required           | Path to manifest directory (physical.yaml, semantic.yaml, policy.yaml) |
+| `--log-level` | From logging config | Override root log level: DEBUG, INFO, WARNING, ERROR, CRITICAL        |
+| `--transport` | `stdio`            | Transport type: `stdio` (HTTP planned for future release)              |
+
+### Logging Configuration
+
+Logging is configured via `logging_conf.yaml` in the config directory. The file follows
+Python's standard `logging.config.dictConfig` format.
+
+Copy the provided template to get started:
+
+```bash
+cp conf/logging_conf.yaml.template <config-dir>/logging_conf.yaml
+```
+
+**Default behaviour (used when no `logging_conf.yaml` is present):**
+
+- Logs go to both `stderr` (console) and a rotating file at `./hypervisor-logs/hypervisor.log`
+- The log directory is created automatically if it does not exist
+- The resolved log file path is printed to `stderr` at startup
+- Root log level: `INFO`
+- File rotation: 10 MB per file, 5 backup files
+
+**Key tunable fields in `logging_conf.yaml`:**
+
+| Field | Default | Description |
+|:------|:--------|:------------|
+| `root.level` | `INFO` | Root log level (overridable with `--log-level`) |
+| `handlers.file_handler.filename` | `./hypervisor-logs/hypervisor.log` | Log file path (relative to CWD) |
+| `handlers.file_handler.maxBytes` | `10485760` (10 MB) | Max file size before rotation |
+| `handlers.file_handler.backupCount` | `5` | Number of backup files to keep |
+
+> **Note:** Logs must never go to `stdout` when using stdio transport — that stream is reserved for JSON-RPC responses.
 
 ### 3. Send a Request
 
@@ -153,7 +183,7 @@ uv run mypy src/
 ```
 adp-hypervisor/
 ├── pyproject.toml              # Project configuration
-├── conf/                       # Manifest templates
+├── conf/                       # Manifest templates (physical, semantic, policy, logging)
 ├── examples/                   # Ready-to-run demo (Docker + manifests)
 ├── src/adp_hypervisor/         # Main hypervisor package
 │   ├── server.py               # ADPServer main class

conf/logging_conf.yaml.template

@@ -0,0 +1,52 @@
+# Copyright 2026 Datastrato, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+# ADP Hypervisor Logging Configuration
+#
+# This file configures the Python logging system via logging.config.dictConfig.
+# Copy this template to your runtime config directory as logging_conf.yaml and
+# adjust the values to suit your environment.
+#
+# Usage:
+#   cp conf/logging_conf.yaml.template <config-dir>/logging_conf.yaml
+#
+# The log level can also be overridden at startup with --log-level.
+
+version: 1
+disable_existing_loggers: false
+
+formatters:
+  standard:
+    format: "%(asctime)s [%(levelname)s] %(name)s: %(message)s"
+    datefmt: "%Y-%m-%dT%H:%M:%S"
+
+handlers:
+  console:
+    class: logging.StreamHandler
+    formatter: standard
+    stream: ext://sys.stderr
+
+  file_handler:
+    class: logging.handlers.RotatingFileHandler
+    formatter: standard
+    filename: ./hypervisor-logs/hypervisor.log
+    maxBytes: 10485760   # 10 MB
+    backupCount: 5
+    encoding: utf-8
+
+root:
+  level: INFO
+  handlers:
+    - console
+    - file_handler

src/adp_hypervisor/__main__.py

@@ -28,8 +28,13 @@
 import argparse
 import asyncio
 import logging
+import logging.config
+import logging.handlers
 import sys
 from pathlib import Path
+from typing import Any
+
+import yaml
 
 from adp_hypervisor.manifest.yaml_provider import YamlManifestProvider
 from adp_hypervisor.policy import UserRoleConfig, YamlRoleResolver
@@ -41,6 +46,38 @@
 _VALID_LOG_LEVELS = ("DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL")
 _VALID_TRANSPORTS = ("stdio", "http")
 
+# Built-in default logging config, matches conf/logging_conf.yaml.template.
+# Used when no logging_conf.yaml is present in the config directory.
+_DEFAULT_LOGGING_CONFIG: dict[str, Any] = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "standard": {
+            "format": "%(asctime)s [%(levelname)s] %(name)s: %(message)s",
+            "datefmt": "%Y-%m-%dT%H:%M:%S",
+        }
+    },
+    "handlers": {
+        "console": {
+            "class": "logging.StreamHandler",
+            "formatter": "standard",
+            "stream": "ext://sys.stderr",
+        },
+        "file_handler": {
+            "class": "logging.handlers.RotatingFileHandler",
+            "formatter": "standard",
+            "filename": "./hypervisor-logs/hypervisor.log",
+            "maxBytes": 10485760,
+            "backupCount": 5,
+            "encoding": "utf-8",
+        },
+    },
+    "root": {
+        "level": "INFO",
+        "handlers": ["console", "file_handler"],
+    },
+}
+
 
 def _build_parser() -> argparse.ArgumentParser:
     """Build the CLI argument parser."""
@@ -56,9 +93,9 @@ def _build_parser() -> argparse.ArgumentParser:
     )
     parser.add_argument(
         "--log-level",
-        default="INFO",
+        default=None,
         choices=_VALID_LOG_LEVELS,
-        help="Logging level (default: INFO)",
+        help="Override the root logging level (default: level from logging_conf.yaml or INFO)",
     )
     parser.add_argument(
         "--transport",
@@ -69,13 +106,78 @@ def _build_parser() -> argparse.ArgumentParser:
     return parser
 
 
-def _configure_logging(level: str) -> None:
-    """Configure root logging with a consistent format."""
-    logging.basicConfig(
-        level=getattr(logging, level),
-        format="%(asctime)s [%(levelname)s] %(name)s: %(message)s",
-        stream=sys.stderr,
-    )
+def _load_logging_config(config_dir: Path) -> dict[str, Any]:
+    """Load logging configuration from config_dir/logging_conf.yaml.
+
+    Falls back to the built-in default when the file is absent.
+
+    Args:
+        config_dir: The runtime config directory.
+
+    Returns:
+        A dict suitable for logging.config.dictConfig.
+    """
+    logging_conf_path = config_dir / "logging_conf.yaml"
+    if logging_conf_path.exists():
+        try:
+            raw = yaml.safe_load(logging_conf_path.read_text(encoding="utf-8"))
+            if isinstance(raw, dict):
+                return raw
+            print(
+                f"Warning: {logging_conf_path} is not a YAML mapping (got {type(raw).__name__}), "
+                "using built-in logging defaults.",
+                file=sys.stderr,
+            )
+        except (yaml.YAMLError, OSError):
+            print(
+                f"Warning: failed to parse {logging_conf_path}, using built-in logging defaults.",
+                file=sys.stderr,
+            )
+    return _DEFAULT_LOGGING_CONFIG
+
+
+def _ensure_log_directories(config: dict[str, Any]) -> None:
+    """Create parent directories for all file-based log handlers.
+
+    Scans every handler in the config dict, resolves the parent directory
+    for any handler that has a ``filename`` key, and creates it if missing.
+    Emits a startup notice to stderr for each resolved log file path.
+
+    Args:
+        config: The logging config dict (as passed to dictConfig).
+    """
+    handlers = config.get("handlers", {})
+    for _name, handler_cfg in handlers.items():
+        filename = handler_cfg.get("filename")
+        if not filename:
+            continue
+        log_path = Path(filename).resolve()
+        log_dir = log_path.parent
+        log_dir.mkdir(parents=True, exist_ok=True)
+        print(
+            f"ADP Hypervisor: logging to file {log_path}",
+            file=sys.stderr,
+        )
+
+
+def _configure_logging(config_dir: Path, level_override: str | None) -> None:
+    """Load and apply logging configuration.
+
+    Reads logging_conf.yaml from config_dir (falls back to built-in defaults),
+    ensures all file-handler directories exist, then applies the config via
+    dictConfig. Overrides the root log level when --log-level is provided.
+
+    Args:
+        config_dir: The runtime config directory.
+        level_override: Optional log level string (e.g. "DEBUG") from --log-level.
+    """
+    config = _load_logging_config(config_dir)
+
+    if level_override is not None:
+        config.setdefault("root", {})["level"] = level_override
+
+    _ensure_log_directories(config)
+    logging.config.dictConfig(config)
 
 
 def _create_yaml_provider(config_dir: Path) -> YamlManifestProvider:
@@ -161,22 +263,23 @@ def main(args: list[str] | None = None) -> None:
     parser = _build_parser()
     parsed = parser.parse_args(args)
 
-    _configure_logging(parsed.log_level)
+    config_dir = Path(parsed.config)
+    _configure_logging(config_dir, parsed.log_level)
 
     if parsed.transport == "http":
         logger.error("HTTP transport is not yet implemented")
         sys.exit(1)
 
     transport = StdioTransport()
-    provider = _create_yaml_provider(Path(parsed.config))
-    role_resolver = _create_role_resolver(Path(parsed.config))
+    provider = _create_yaml_provider(config_dir)
+    role_resolver = _create_role_resolver(config_dir)
     server = ADPServer(manifest_provider=provider, transport=transport, role_resolver=role_resolver)
 
     logger.info(
         "Starting ADP Hypervisor: config=%s, transport=%s, log_level=%s",
         parsed.config,
         parsed.transport,
-        parsed.log_level,
+        parsed.log_level or "from config",
     )
 
     asyncio.run(server.run())

src/adp_hypervisor/handlers/execute.py

@@ -98,6 +98,12 @@ async def handle(self, params: dict[str, Any]) -> BaseModel:
         request = ExecuteRequestParams.model_validate(params)
 
         resource_id = request.intent.resource_id
+        logger.debug(
+            "Execute: started resource=%s, intent_class=%s",
+            resource_id,
+            request.intent.intent_class,
+        )
+
         resource = self._manifest_index.get_resource(resource_id)
         if resource is None:
             raise ResourceNotFoundError(f"Resource not found: {resource_id!r}")
@@ -134,8 +140,9 @@ async def handle(self, params: dict[str, Any]) -> BaseModel:
         # based on the result set and pass it back via next_cursor.
 
         logger.info(
-            "Execute: resource=%s, intent_class=%s, rows=%d, duration_ms=%d",
+            "Execute: resource=%s, backend=%s, intent_class=%s, rows=%d, duration_ms=%d",
             resource_id,
+            resource.backend_id,
             request.intent.intent_class,
             len(result.rows),
             duration_ms,

src/adp_hypervisor/handlers/initialize.py

@@ -94,7 +94,7 @@ async def handle(self, params: dict[str, Any]) -> BaseModel:
         """
         request = InitializeRequestParams.model_validate(params)
 
-        logger.info(
+        logger.debug(
             "Initialize request from %s/%s, protocol version: %s",
             request.client_info.name,
             request.client_info.version,
@@ -108,6 +108,13 @@ async def handle(self, params: dict[str, Any]) -> BaseModel:
                 f"Supported versions: {supported}"
             )
 
+        logger.info(
+            "Initialize: client=%s/%s, protocol_version=%s accepted",
+            request.client_info.name,
+            request.client_info.version,
+            request.protocol_version,
+        )
+
         return InitializeResult(
             protocol_version=request.protocol_version,
             capabilities=self._capabilities,

src/adp_hypervisor/handlers/ping.py

@@ -18,13 +18,16 @@
 Implements the adp.ping method which provides a simple health check.
 """
 
+import logging
 from typing import Any
 
 from pydantic import BaseModel
 
 from adp_hypervisor.handlers.base import Handler
 from adp_hypervisor.protocol.types import EmptyResult
 
+logger = logging.getLogger(__name__)
+
 
 class PingHandler(Handler):
     """Handler for the adp.ping method.
@@ -46,4 +49,5 @@ async def handle(self, params: dict[str, Any]) -> BaseModel:
         Returns:
             An empty result indicating the server is alive.
         """
+        logger.debug("Ping received")
         return EmptyResult()

src/adp_hypervisor/manifest/yaml_provider.py

@@ -60,7 +60,11 @@ def load(self) -> None:
         self._physical = self._load_physical()
         self._semantic = self._load_semantic()
         self._policy = self._load_policy()
-        logger.info("Manifests loaded successfully")
+        logger.info(
+            "Manifests loaded: backends=%d, resources=%d",
+            len(self._physical.backends),
+            len(self._semantic.resources),
+        )
 
     def get_physical_manifest(self) -> PhysicalManifest:
         self._ensure_loaded()
@@ -88,6 +92,7 @@ def _load_yaml(self, path: Path) -> dict:  # type: ignore[type-arg]
             data = yaml.safe_load(f)
         if not isinstance(data, dict):
             raise ValueError(f"Expected a YAML mapping in {path}, got {type(data).__name__}")
+        logger.debug("Loaded YAML: %s (%d top-level keys)", path, len(data))
         return data
 
     def _load_physical(self) -> PhysicalManifest: