feat: add structured logging and integrate formatting into CI/CD

.github/workflows/ci.yml

@@ -21,7 +21,33 @@ jobs:
         env:
           GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }}
 
+  format:
+    if: (github.event_name == 'push' && github.ref == 'refs/heads/main') || (github.event_name == 'pull_request' && github.event.action != 'closed')
+    runs-on: ubuntu-latest
+    steps:
+      - uses: actions/checkout@v4
+
+      - name: Install uv
+        uses: astral-sh/setup-uv@v3
+        with:
+          enable-cache: true
+          cache-dependency-glob: |
+            pyproject.toml
+            *.py
+
+      - name: Set up Python
+        run: uv python install 3.12
+
+      - name: Install dependencies
+        run: |
+          uv venv --python 3.12
+          make sync
+
+      - name: Format code
+        run: make format
+
   lint:
+    needs: format
     if: (github.event_name == 'push' && github.ref == 'refs/heads/main') || (github.event_name == 'pull_request' && github.event.action != 'closed')
     runs-on: ubuntu-latest
     steps:
@@ -125,7 +151,7 @@ jobs:
         run: make test-unit
 
   release:
-    needs: [lint, type-check, test]
+    needs: [format, lint, type-check, test]
     if: (github.event_name == 'push' && github.ref == 'refs/heads/main') || (github.event.action == 'closed' && github.event.pull_request.merged == true)
     runs-on: ubuntu-latest
     permissions:

.pre-commit-config.yaml

@@ -1,6 +1,13 @@
 repos:
   - repo: local
     hooks:
+      - id: format-check
+        name: Format code with ruff
+        entry: make format
+        language: system
+        stages: [pre-commit]
+        verbose: true
+        pass_filenames: false
       - id: lint-check
         name: Run ruff linter
         entry: make lint

Makefile

@@ -116,8 +116,9 @@ test-all: ## Run all tests including integration tests
 # Branch Validation
 # ----------------------------
 
-validate-branch: ## Run linting, type checks, and tests
+validate-branch: ## Run formatting, linting, type checks, and tests
 	@echo "🔍 Running branch validation..."
+	$(MAKE) format
 	$(MAKE) lint
 	$(MAKE) type-check
 	$(MAKE) test

README.md

@@ -15,9 +15,10 @@
 A **modern Python foundation** designed for AI systems that need to work reliably in production:
 
 - **Modern Python Tooling** - Python 3.12+, FastAPI, Pydantic, type hints throughout
+- **Production Logging** - Structured JSON logging with correlation tracking and dual-mode rendering
 - **Development Automation** - Pre-configured linting, formatting, testing, and validation
 - **Production-Ready Structure** - Organized for maintainability and scaling
-- **Comprehensive Testing** - Unit, functional, and integration test patterns
+- **Comprehensive Testing** - Unit, functional, and integration test patterns (21+ logging tests included)
 - **CI/CD Ready** - GitHub Actions, pre-commit hooks, semantic versioning
 - **Documentation Standards** - Clear guides for development and deployment
 
@@ -93,9 +94,11 @@ make test-all          # Complete test suite
 ai-base-template/
 ├── ai_base_template/      # Your service code goes here
 │   ├── __init__.py       
-│   └── main.py           # Simple starting point
+│   ├── main.py           # Simple starting point with logging integration
+│   └── logging.py        # Production structured logging system
 ├── tests/                # Comprehensive test suite
-│   └── test_main.py      # Example test patterns
+│   ├── test_main.py      # Example test patterns
+│   └── test_logging.py   # 21+ logging system tests
 ├── research/             # Notebooks and experiments
 │   └── EDA.ipynb        # Exploratory work stays here
 ├── Makefile             # All automation commands
@@ -114,6 +117,67 @@ Stop reinventing infrastructure. Focus on your models while using battle-tested
 ### Technical Leaders
 Give your team a consistent, production-ready starting point that embodies engineering best practices from day one.
 
+## 📊 Production Logging System
+
+This template includes a **production-grade structured logging system** built with structlog that handles the observability requirements of real-world AI systems.
+
+### Dual-Mode Logging
+
+**Development Mode** - Human-readable format for debugging:
+```bash
+22:45:00 [INFO] main: Processing request [HTTP 200, 150ms, user_id=user-123] [id:req-abc12]
+```
+
+**Production Mode** - Structured JSON for monitoring systems:
+```json
+{
+  "timestamp": "2025-08-31T22:45:00.123Z",
+  "level": "info", 
+  "logger": "main",
+  "message": "Processing request",
+  "context": "default",
+  "extra": {
+    "status_code": 200,
+    "duration_ms": 150,
+    "user_id": "user-123",
+    "correlation_id": "req-abc-123"
+  }
+}
+```
+
+### Built-in Features
+
+- **Correlation ID Tracking** - Trace requests across your entire system
+- **Context Isolation** - Prevent data leakage between concurrent requests
+- **Smart Field Organization** - Important fields (status_code, duration_ms) formatted for readability
+- **Environment-Driven Configuration** - `LOGGING_LEVEL` and `LITELLM_LOG_LEVEL` support
+- **Logger Name Abbreviation** - Clean, readable logger names in development
+
+### Usage Example
+
+```python
+from ai_base_template.logging import configure_structlog, get_logger, bind_contextvars
+
+# Configure for your environment
+configure_structlog(testing=False)  # Production JSON output
+logger = get_logger(__name__)
+
+# Bind correlation ID at request start
+bind_contextvars(correlation_id="req-123", user_id="user-456")
+
+# All subsequent logs will include context automatically
+logger.info("Processing AI request", model="gpt-4", tokens=150)
+logger.info("Request completed", status_code=200, duration_ms=1200)
+```
+
+### Integration with AI Systems
+
+The logging system is specifically designed for AI/ML production requirements:
+- **Cost tracking** with built-in fields for model usage
+- **Performance monitoring** with latency and token usage
+- **Request tracing** across complex AI pipelines
+- **Error categorization** for model vs. infrastructure failures
+
 ## 📚 Learn More
 
 ### Core Methodology
@@ -126,6 +190,7 @@ Give your team a consistent, production-ready starting point that embodies engin
 ### Technologies Used
 - [FastAPI](https://fastapi.tiangolo.com/) - Modern Python web framework
 - [Pydantic](https://docs.pydantic.dev/) - Data validation using type annotations
+- [structlog](https://www.structlog.org/) - Structured logging for production systems
 - [uv](https://docs.astral.sh/uv/) - Modern Python package management
 
 ## 🤝 Contributing

ai_base_template/__init__.py

@@ -1,3 +1,3 @@
 """AI Flora Mind - Python AI Package"""
 
-__version__ = "1.0.6"
+__version__ = "1.0.6"

ai_base_template/logging.py

@@ -0,0 +1,179 @@
+import logging
+import os
+import sys
+from typing import Any
+
+import structlog
+from structlog.types import EventDict, WrappedLogger
+
+LOG_SPECIFIC_FIELDS = {
+    "timestamp",
+    "logger",
+    "message",
+    "context",
+    "level",
+}
+
+
+def _process_log_fields(logger: WrappedLogger, log_method: str, event_dict: EventDict) -> EventDict:
+    # Rename "event" to "message"
+    event_dict["message"] = event_dict.pop("event", "")
+    event_dict["context"] = structlog.contextvars.get_contextvars().get("context", "default")
+
+    # Create the "extra" dictionary for unexpected keys
+    extra_fields = {key: event_dict.pop(key) for key in list(event_dict.keys()) if key not in LOG_SPECIFIC_FIELDS}
+
+    # Add the "extra" dictionary if it contains any fields
+    if extra_fields:
+        event_dict["extra"] = extra_fields
+
+    return event_dict
+
+
+def _abbreviate_logger_name(logger_name: str) -> str:
+    """Abbreviate logger names for readable output."""
+    if not logger_name.startswith("ai_base_template"):
+        return logger_name
+
+    # Remove the ai_base_template prefix and return the meaningful part
+    parts = logger_name.replace("ai_base_template.", "").split(".")
+
+    # Keep last 2 parts for context (e.g., "core.chat", "services.llm")
+    if len(parts) >= 2:
+        return f"{parts[-2]}.{parts[-1]}"
+    return parts[-1] if parts else logger_name
+
+
+def _format_extra_fields(extra: dict[str, Any]) -> str:
+    """Format extra fields for human-readable output."""
+    if not extra:
+        return ""
+
+    # Prioritize important fields
+    important_keys = ["status_code", "duration_ms", "response_size_bytes", "error", "sql_query"]
+    formatted_parts = []
+
+    # Add important fields first
+    for key in important_keys:
+        if key in extra:
+            value = extra[key]
+            if key == "duration_ms":
+                formatted_parts.append(f"{value}ms")
+            elif key == "status_code":
+                formatted_parts.append(f"HTTP {value}")
+            elif key == "response_size_bytes":
+                formatted_parts.append(f"{value}B")
+            else:
+                formatted_parts.append(f"{key}={value}")
+
+    # Add remaining fields
+    remaining = {k: v for k, v in extra.items() if k not in important_keys}
+    for key, value in remaining.items():
+        if len(str(value)) > 50:  # Truncate long values
+            formatted_parts.append(f"{key}={str(value)[:47]}...")
+        else:
+            formatted_parts.append(f"{key}={value}")
+
+    return f" [{', '.join(formatted_parts)}]" if formatted_parts else ""
+
+
+class HumanReadableRenderer:
+    """Human-readable log formatter for testing environments."""
+
+    def __call__(self, logger: WrappedLogger, log_method: str, event_dict: EventDict) -> str:
+        """Render log entry in human-readable format: HH:MM:SS [LEVEL] logger: message [key_info] [correlation_id]"""
+        # Extract components
+        timestamp = event_dict.get("timestamp", "")
+        level = event_dict.get("level", "").upper()
+        logger_name = _abbreviate_logger_name(event_dict.get("logger", ""))
+        message = event_dict.get("message", "")
+        extra = event_dict.get("extra", {})
+        correlation_id = structlog.contextvars.get_contextvars().get("correlation_id", "")
+
+        # Format timestamp to HH:MM:SS
+        time_part = ""
+        if timestamp:
+            try:
+                # Extract time from ISO timestamp (e.g., "2025-01-27T14:30:45.123456")
+                if "T" in timestamp:
+                    time_part = timestamp.split("T")[1].split(".")[0]  # Get HH:MM:SS part
+                else:
+                    time_part = timestamp.split(" ")[1].split(".")[0] if " " in timestamp else timestamp
+            except (IndexError, AttributeError):
+                time_part = timestamp
+
+        # Build the formatted message
+        parts = []
+        if time_part:
+            parts.append(time_part)
+        if level:
+            parts.append(f"[{level}]")
+        if logger_name:
+            parts.append(f"{logger_name}:")
+        if message:
+            parts.append(message)
+
+        base_message = " ".join(parts)
+
+        # Add extra fields if present
+        extra_str = _format_extra_fields(extra)
+        if extra_str:
+            base_message += extra_str
+
+        # Add correlation ID if present
+        if correlation_id:
+            base_message += f" [id:{correlation_id[:8]}]"
+
+        return base_message
+
+
+def configure_structlog(testing: bool = False) -> None:
+    """Configure structured logging with JSON or human-readable output format."""
+    # Get logging level from environment or default to INFO
+    log_level = os.environ.get("LOGGING_LEVEL", "INFO").upper()
+    level = getattr(logging, log_level, logging.INFO)
+
+    logging.basicConfig(format="%(message)s", level=level, stream=sys.stdout)
+    logging.getLogger().setLevel(level)
+
+    # Silence LiteLLM's verbose logging - let our app control what gets logged
+    litellm_logger = logging.getLogger("LiteLLM")
+    litellm_log_level = os.environ.get("LITELLM_LOG_LEVEL", "WARNING").upper()
+    litellm_level = getattr(logging, litellm_log_level, logging.WARNING)
+    litellm_logger.setLevel(litellm_level)
+
+    # Common processors
+    base_processors = [
+        structlog.stdlib.add_log_level,
+        structlog.stdlib.add_logger_name,
+        structlog.contextvars.merge_contextvars,
+        _process_log_fields,
+        structlog.processors.TimeStamper(fmt="iso"),
+    ]
+
+    # Add renderer based on testing flag
+    renderer = HumanReadableRenderer() if testing else structlog.processors.JSONRenderer()
+    processors = base_processors + [renderer]
+
+    structlog.configure(
+        processors=processors,  # type: ignore[arg-type]
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        wrapper_class=structlog.make_filtering_bound_logger(level),
+        cache_logger_on_first_use=True,
+    )
+
+
+# Direct assignments for context management
+clear_context_fields = structlog.contextvars.clear_contextvars
+bind_contextvars = structlog.contextvars.bind_contextvars
+get_contextvars = structlog.contextvars.get_contextvars
+
+
+def get_correlation_id() -> str:
+    """Get correlation ID from context or return default."""
+    contextvars = structlog.contextvars.get_contextvars()
+    return str(contextvars.get("correlation_id", "unknown"))
+
+
+def get_logger(name: str = "") -> structlog.stdlib.BoundLogger:
+    return structlog.get_logger(name or __name__)  # type: ignore

ai_base_template/main.py

@@ -1,12 +1,22 @@
 """Main module for AI Base Template service."""
 
+from .logging import configure_structlog, get_logger
+
+# Configure logging
+configure_structlog(testing=True)
+logger = get_logger(__name__)
+
 
 def hello_world() -> str:
-    """Simple function to test the package."""
-    return "Hello from AI Base Template!"
+    logger.info("hello_world function called")
+    result = "Hello from AI Base Template!"
+    logger.info("hello_world function returning result", result=result)
+    return result
 
 
 def get_version() -> str:
-    """Get the package version."""
+    logger.info("get_version function called")
     from . import __version__
-    return __version__
+
+    logger.info("Version retrieved", version=__version__)
+    return __version__

pyproject.toml

@@ -24,6 +24,7 @@ dependencies = [
     # Core dependencies
     "pydantic>=2.11.5",
     "pydantic-settings>=2.9.1",
+    "structlog>=25.4.0",
 ]
 
 [project.optional-dependencies]