Fix #82: audit and standardize logging behavior

docs/logging-guidelines.md

@@ -0,0 +1,25 @@
+# Logging Guidelines
+
+These rules keep logging useful without leaking sensitive data.
+
+## Principles
+
+- Use module loggers: `logger = logging.getLogger(__name__)`.
+- Keep user-facing CLI output in `console.print(...)`; use `logger.*` for diagnostics.
+- Never log raw prompts, private reasoning text, API keys, auth headers, or tokens.
+- Prefer structured metadata in logs (model name, token counts, timings, IDs).
+- Use levels consistently:
+  - `DEBUG`: high-volume diagnostics safe for local troubleshooting.
+  - `INFO`: normal progress and timing.
+  - `WARNING`: retries, degraded behavior, recoverable failures.
+  - `ERROR`: terminal failures for the current operation.
+
+## Provider Debug Logs
+
+`extropy/core/providers/logging.py` writes sanitized JSON logs:
+
+- Secret fields are replaced with `[REDACTED_SECRET]`.
+- Prompt/content-like text fields are replaced with `[REDACTED_TEXT length=N]`.
+- Responses are summarized and sanitized before writing.
+
+If you add new request/response fields, ensure they pass through the sanitizer.

extropy/core/models/simulation.py

@@ -310,6 +310,10 @@ class ReasoningContext(BaseModel):
     background_context: str | None = Field(
         default=None, description="Scenario-level background context"
     )
+    identity_threat_summary: str | None = Field(
+        default=None,
+        description="Deterministic identity-relevance framing when scenario content threatens group identity",
+    )
     agent_names: dict[str, str] = Field(
         default_factory=dict,
         description="Mapping of agent_id → first name for resolving peer references",
@@ -357,6 +361,10 @@ class ReasoningResponse(BaseModel):
     position: str | None = Field(
         default=None, description="Classified position (filled by Pass 2)"
     )
+    public_position: str | None = Field(
+        default=None,
+        description="Public-facing position when THINK/SAY diverges (high fidelity)",
+    )
     sentiment: float | None = Field(
         default=None, description="Sentiment value (-1 to 1)"
     )

extropy/core/providers/logging.py

@@ -1,10 +1,34 @@
 """Shared logging helpers for LLM providers."""
 
 import json
+import logging
 from datetime import datetime
 from pathlib import Path
 from typing import Any
 
+logger = logging.getLogger(__name__)
+
+_SECRET_KEY_MARKERS = ("api_key", "authorization", "token", "secret", "password")
+_TOKEN_COUNT_KEYS = {
+    "prompt_tokens",
+    "completion_tokens",
+    "total_tokens",
+    "input_tokens",
+    "output_tokens",
+}
+_TEXT_KEY_MARKERS = (
+    "prompt",
+    "content",
+    "input",
+    "output",
+    "text",
+    "message",
+    "reasoning",
+    "statement",
+    "thought",
+    "elaboration",
+)
+
 
 def get_logs_dir() -> Path:
     """Get logs directory, create if needed."""
@@ -13,41 +37,98 @@ def get_logs_dir() -> Path:
     return logs_dir
 
 
+def _sanitize_for_logs(value: Any, key_hint: str = "") -> Any:
+    """Recursively sanitize payloads before persisting debug logs."""
+    key = key_hint.lower()
+    if key in _TOKEN_COUNT_KEYS:
+        return value
+    if any(marker in key for marker in _SECRET_KEY_MARKERS):
+        return "[REDACTED_SECRET]"
+
+    if isinstance(value, dict):
+        return {
+            str(k): _sanitize_for_logs(v, key_hint=str(k))
+            for k, v in value.items()
+        }
+
+    if isinstance(value, list):
+        return [_sanitize_for_logs(item, key_hint=key_hint) for item in value]
+
+    if isinstance(value, tuple):
+        return [_sanitize_for_logs(item, key_hint=key_hint) for item in value]
+
+    if isinstance(value, str):
+        if any(marker in key for marker in _TEXT_KEY_MARKERS):
+            return f"[REDACTED_TEXT length={len(value)}]"
+        if len(value) > 200:
+            return value[:200] + "...[truncated]"
+        return value
+
+    return value
+
+
+def _serialize_response(response: Any) -> Any:
+    """Convert provider response to a serializable, sanitized structure."""
+    if isinstance(response, dict):
+        return _sanitize_for_logs(response, key_hint="response")
+
+    if hasattr(response, "model_dump"):
+        try:
+            dumped = response.model_dump(mode="json", warnings=False)
+            return _sanitize_for_logs(dumped, key_hint="response")
+        except Exception:
+            pass
+
+    usage = getattr(response, "usage", None)
+    usage_dict = None
+    if usage is not None:
+        usage_dict = _sanitize_for_logs(
+            getattr(usage, "__dict__", str(usage)),
+            key_hint="usage",
+        )
+
+    summary = {
+        "type": type(response).__name__,
+    }
+    model_name = getattr(response, "model", None)
+    if model_name:
+        summary["model"] = model_name
+    response_id = getattr(response, "id", None)
+    if response_id:
+        summary["id"] = response_id
+    if usage_dict is not None:
+        summary["usage"] = usage_dict
+
+    return summary
+
+
 def log_request_response(
     function_name: str,
     request: dict,
     response: Any,
     provider: str = "",
     sources: list[str] | None = None,
 ) -> None:
-    """Log full request and response to a JSON file."""
+    """Log sanitized request/response metadata to a JSON file."""
     logs_dir = get_logs_dir()
     timestamp = datetime.now().strftime("%Y%m%d_%H%M%S_%f")
     prefix = f"{provider}_" if provider else ""
     log_file = logs_dir / f"{timestamp}_{prefix}{function_name}.json"
 
-    response_dict = None
-    if hasattr(response, "model_dump"):
-        try:
-            response_dict = response.model_dump(mode="json", warnings=False)
-        except Exception:
-            response_dict = str(response)
-    elif hasattr(response, "__dict__"):
-        response_dict = str(response)
-    else:
-        response_dict = str(response)
-
     log_data = {
         "timestamp": datetime.now().isoformat(),
         "function": function_name,
         "provider": provider,
-        "request": request,
-        "response": response_dict,
+        "request": _sanitize_for_logs(request, key_hint="request"),
+        "response": _serialize_response(response),
         "sources_extracted": sources or [],
     }
 
-    with open(log_file, "w") as f:
-        json.dump(log_data, f, indent=2, default=str)
+    try:
+        with open(log_file, "w", encoding="utf-8") as f:
+            json.dump(log_data, f, indent=2, default=str)
+    except Exception as exc:
+        logger.warning("Failed to write provider debug log %s: %s", log_file, exc)
 
 
 def extract_error_summary(error_msg: str) -> str:

extropy/population/network/metrics.py

@@ -5,11 +5,14 @@
 - Node metrics: PageRank, betweenness, cluster ID, echo chamber score
 """
 
+import logging
 from collections import defaultdict
 from typing import Any
 
 from ...core.models import NetworkMetrics, NodeMetrics
 
+logger = logging.getLogger(__name__)
+
 try:
     import networkx as nx
 
@@ -203,7 +206,7 @@ def validate_network(
     Args:
         edges: List of edge dictionaries
         agent_ids: List of agent IDs
-        verbose: If True, print detailed metrics
+        verbose: If True, log detailed metrics
 
     Returns:
         Tuple of (is_valid, metrics, warnings)
@@ -212,25 +215,25 @@ def validate_network(
     is_valid, warnings = metrics.is_valid()
 
     if verbose:
-        print("Network Validation Report:")
-        print(f"  Nodes: {metrics.node_count}")
-        print(f"  Edges: {metrics.edge_count}")
-        print(f"  Avg Degree: {metrics.avg_degree:.2f}")
-        print(f"  Clustering: {metrics.clustering_coefficient:.3f}")
-        print(
+        logger.info("Network Validation Report:")
+        logger.info("  Nodes: %s", metrics.node_count)
+        logger.info("  Edges: %s", metrics.edge_count)
+        logger.info("  Avg Degree: %.2f", metrics.avg_degree)
+        logger.info("  Clustering: %.3f", metrics.clustering_coefficient)
+        logger.info(
             f"  Avg Path Length: {metrics.avg_path_length:.2f}"
             if metrics.avg_path_length
             else "  Avg Path Length: N/A (disconnected)"
         )
-        print(f"  Modularity: {metrics.modularity:.3f}")
-        print(f"  Largest Component: {metrics.largest_component_ratio:.1%}")
-        print(f"  Degree Assortativity: {metrics.degree_assortativity:.3f}")
+        logger.info("  Modularity: %.3f", metrics.modularity)
+        logger.info("  Largest Component: %.1f%%", metrics.largest_component_ratio * 100)
+        logger.info("  Degree Assortativity: %.3f", metrics.degree_assortativity)
 
         if warnings:
-            print("\nWarnings:")
+            logger.info("Warnings:")
             for w in warnings:
-                print(f"  - {w}")
+                logger.info("  - %s", w)
         else:
-            print("\nAll metrics within expected ranges.")
+            logger.info("All metrics within expected ranges.")
 
     return is_valid, metrics, warnings

extropy/population/spec_builder/hydrator.py

@@ -163,14 +163,14 @@ def hydrate_attributes(
     population = description
 
     def report(step: str, status: str, count: int | None = None):
-        """Report progress via callback or print."""
+        """Report progress via callback or logger."""
         if on_progress:
             on_progress(step, status, count)
         else:
             if count is not None:
-                print(f"  {step}: {status} ({count})")
+                logger.info("  %s: %s (%s)", step, status, count)
             else:
-                print(f"  {step}: {status}")
+                logger.info("  %s: %s", step, status)
 
     def make_retry_callback(step: str) -> RetryCallback:
         """Create a retry callback for a specific step."""