feat(obs): safe text chunker and AI observability logging (#9)

* feat(obs): add structured json logging and safe text chunker

* test(obs): verify chunker overlap and ai call logging

app/chunking.py

@@ -1,9 +1,20 @@
 def chunk_text(text: str, size_tokens: int = 500, overlap_tokens: int = 50) -> list[tuple[str, int]]:
+    """Splits text into chunks of `size_tokens` with `overlap_tokens` overlap."""
+    if not text.strip():
+        return []
+        
+    # Safety check: overlap must be strictly less than size
+    if overlap_tokens >= size_tokens:
+        overlap_tokens = size_tokens - 1
+        
     words = text.split()
     chunks = []
+    step = size_tokens - overlap_tokens
     i = 0
+    
     while i < len(words):
         chunk_words = words[i:i + size_tokens]
         chunks.append((" ".join(chunk_words), len(chunk_words)))
-        i += size_tokens - overlap_tokens
+        i += step
+        
     return chunks

app/routers/hubs.py

@@ -15,6 +15,7 @@ from app.idempotency import (
 from app.chunking import chunk_text
 from app.services.embeddings import embed_texts
 from app.services.gemini import hub_insights
+from app.services.observability import log_ai_call
 
 router = APIRouter(prefix="/hubs", tags=["hubs"])
 
@@ -80,8 +81,14 @@ def create_hub(
         release_claim(db, user_id, key)
         raise AppError(409, "HUB_NAME_CONFLICT", "You already have a hub with this name.")
 
-    # 2. AI Summary
-    summary, questions = hub_insights(body.content) if body.content else (None, [])
+    # 2. AI Summary (Wrapped in observability)
+    if body.content:
+        summary, questions = log_ai_call(
+            "hub_insights", user_id, None, 
+            hub_insights, body.content
+        )
+    else:
+        summary, questions = None, []
 
     # 3. Create Hub
     new_hub = Hub(
@@ -97,7 +104,6 @@ def create_hub(
         doc_count = 0
         chunk_count = 0
         
-        # ---- THIS IS THE BLOCK YOU ASKED ABOUT ----
         if body.content.strip():
             doc_count = 1
             new_doc = Document(
@@ -110,7 +116,13 @@ def create_hub(
             try:
                 chunks_data = chunk_text(body.content)
                 texts = [c[0] for c in chunks_data]
-                embeddings = embed_texts(texts)
+                
+                # Embeddings (Wrapped in observability)
+                embeddings = log_ai_call(
+                    "embed_texts", user_id, new_hub.id, 
+                    embed_texts, texts
+                )
+                
                 for i, ((text, tokens), emb) in enumerate(zip(chunks_data, embeddings)):
                     db.add(Chunk(
                         document_id=new_doc.id, hub_id=new_hub.id, owner_id=user_id, 
@@ -122,7 +134,6 @@ def create_hub(
                 # Graceful degradation: AI failed, but we keep the hub
                 new_doc.status = "failed"
                 new_doc.error_message = "Embedding failed"
-        # -------------------------------------------
 
         db.commit()
         db.refresh(new_hub)

app/services/observability.py

@@ -0,0 +1,34 @@
+import time
+import json
+import logging
+from uuid import UUID
+from typing import Callable, Any
+from app.services.gemini import AiUnavailable
+
+logger = logging.getLogger("uvicorn.error")
+
+def log_ai_call(operation: str, user_id: UUID | str, hub_id: UUID | str | None, fn: Callable, *args, **kwargs) -> Any:
+    """Wraps an AI call, logs the duration and status, and re-raises exceptions."""
+    start = time.monotonic()
+    status = "success"
+    
+    try:
+        result = fn(*args, **kwargs)
+        return result
+    except Exception as e:
+        status = "error" if not isinstance(e, AiUnavailable) else e.kind
+        raise e
+    finally:
+        duration_ms = int((time.monotonic() - start) * 1000)
+        
+        log_data = {
+            "event": "ai_call",
+            "operation": operation,
+            "user_id": str(user_id),
+            "hub_id": str(hub_id) if hub_id else None,
+            "duration_ms": duration_ms,
+            "status": status,
+            "timestamp": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime())
+        }
+        # This prints to stdout (or Uvicorn's error logger)
+        logger.info(json.dumps(log_data))

tests/test_chunking.py

@@ -0,0 +1,19 @@
+from app.chunking import chunk_text
+
+def test_chunk_text_basic():
+    text = "word " * 1000
+    chunks = chunk_text(text, size_tokens=500, overlap_tokens=50)
+    assert len(chunks) == 3
+    # First chunk should have 500 words
+    assert chunks[0][1] == 500
+    # Second chunk should overlap by 50 words (starts at word 450)
+    assert chunks[1][1] == 500
+
+def test_chunk_text_infinite_loop_prevention():
+    text = "word " * 1000
+    # This would cause an infinite loop if we didn't fix the math
+    chunks = chunk_text(text, size_tokens=500, overlap_tokens=600)
+    assert len(chunks) > 0 # It survived!
+
+def test_chunk_text_empty():
+    assert chunk_text("") == []

tests/test_observability.py

@@ -0,0 +1,14 @@
+from unittest.mock import patch
+from app.services.observability import log_ai_call
+
+def test_log_ai_call_success(caplog):
+    import logging
+    caplog.set_level(logging.INFO, logger="uvicorn.error")
+    
+    def dummy_ai(): return "ok"
+    
+    result = log_ai_call("test_op", "user1", "hub1", dummy_ai)
+    assert result == "ok"
+    assert '"event": "ai_call"' in caplog.text
+    assert '"operation": "test_op"' in caplog.text
+    assert '"status": "success"' in caplog.text