feat: backup DB automatico e logging strutturato

- backup_db() in db.py: copia in data/backups/*.db
- Backup a ogni avvio + ogni 5 turni
- Mantiene max 20 backup, rimuove i piu vecchi
- Logging strutturato: [LLM] latenza, raw_len
- Logging strutturato: [CYCLE] turn, tool, latenza, success
- Fix: import mancante threading in db.py

src/engine/db.py

@@ -4,15 +4,21 @@ Database module per DCC RPG — Neon Scratch Lounge.
 Gestisce schema SQLite e popolazione iniziale dati.
 """
 
-import sqlite3
 import json
+import logging
 import os
+import shutil
+import sqlite3
 import threading
+import time
+from datetime import datetime
 from pathlib import Path
 
 DB_PATH = Path(__file__).resolve().parent.parent.parent / "data" / "dcc_rpg.db"
 DATA_DIR = Path(__file__).resolve().parent.parent.parent / "data"
 
+log = logging.getLogger(__name__)
+
 _conn_lock = threading.Lock()
 _local = threading.local()
 
@@ -239,6 +245,33 @@ def init_db() -> sqlite3.Connection:
     return conn
 
 
+# ---------------------------------------------------------------------------
+# Backup
+# ---------------------------------------------------------------------------
+
+BACKUP_DIR = DB_PATH.parent / "backups"
+
+
+def backup_db() -> str:
+    """Copia il database in data/backups/dcc_rpg_YYYY-MM-DD_HHMMSS.db.
+    Mantiene al massimo 20 backup, rimuove i piu vecchi."""
+    BACKUP_DIR.mkdir(parents=True, exist_ok=True)
+    ts = datetime.now().strftime("%Y-%m-%d_%H%M%S")
+    dest = BACKUP_DIR / f"dcc_rpg_{ts}.db"
+    try:
+        shutil.copy2(str(DB_PATH), str(dest))
+        log.info("Backup DB creato: %s", dest.name)
+    except FileNotFoundError:
+        log.warning("Nessun DB da backupare (file non trovato)")
+        return ""
+    # Pulisce backup vecchi (mantiene 20)
+    backups = sorted(BACKUP_DIR.glob("dcc_rpg_*.db"), reverse=True)
+    for old in backups[20:]:
+        old.unlink()
+        log.info("Rimosso backup vecchio: %s", old.name)
+    return str(dest)
+
+
 # ---------------------------------------------------------------------------
 # Query helpers
 # ---------------------------------------------------------------------------

src/engine/dm.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import logging
+import time
 
 from src.engine import db, tools
 from src.engine.config import load_from_env
@@ -14,10 +15,14 @@ log = logging.getLogger(__name__)
 
 def _llm_decision(ctx: GameContext, player_action: str, current_area_id: str = "") -> tuple[str, dict, str]:
     prompt = build_prompt(ctx, player_action, current_area_id=current_area_id)
+    t0 = time.perf_counter()
     try:
         raw = llm_ask(prompt, system=SYSTEM_PROMPT)
+        elapsed = time.perf_counter() - t0
+        log.info("[LLM] azione=%s tool=? latenza=%.1fs raw_len=%d", player_action[:40], elapsed, len(raw))
     except Exception as e:
-        log.warning("LLM call failed (%s), fallback a heuristic parser", e)
+        elapsed = time.perf_counter() - t0
+        log.warning("[LLM] fallback heuristico dopo %.1fs: %s", elapsed, e)
         tool, params = fallback_parse(player_action, ctx.characters)
         return tool, params, ""
 
@@ -28,17 +33,13 @@ def _llm_decision(ctx: GameContext, player_action: str, current_area_id: str = "
     narration = decision.get("narration", "")
 
     if not tool:
-        log.info("LLM non ha prodotto tool valido, fallback heuristico")
+        log.info("[DM] tool non valido, fallback heuristico")
         tool, params = fallback_parse(player_action, ctx.characters)
-
-    # Se il JSON era malformato e params sono vuoti, usa l'euristico per i parametri
     elif not params and tool not in ("dm_override",):
-        log.info("Tool %s senza params, integro con fallback euristico", tool)
+        log.info("[DM] tool=%s senza params, integro euristico", tool)
         _, fallback_params = fallback_parse(player_action, ctx.characters)
         params = fallback_params
 
-    # dm_override/narrate: il LLM spesso mette il testo in params.params.text
-    # invece che nel campo narration JSON — lo estraiamo qui
     if tool == "dm_override" and not narration:
         inner = params.get("params", {}) if isinstance(params, dict) else {}
         if isinstance(inner, dict):
@@ -50,6 +51,7 @@ def _llm_decision(ctx: GameContext, player_action: str, current_area_id: str = "
 
 
 def dm_cycle(campaign_id: int, player_action: str) -> dict:
+    t0 = time.perf_counter()
     ctx = GameContext.load(campaign_id)
 
     tool_name, tool_params, narration = _llm_decision(ctx, player_action, current_area_id=ctx.current_area_id)
@@ -66,6 +68,16 @@ def dm_cycle(campaign_id: int, player_action: str) -> dict:
     turn = db.advance_turn(campaign_id)
     db.log_turn(campaign_id, turn, player_action, full_msg)
 
+    # Backup ogni 5 turni
+    if turn > 0 and turn % 5 == 0:
+        db.backup_db()
+
+    elapsed = time.perf_counter() - t0
+    log.info(
+        "[CYCLE] turn=%d tool=%s action=%s latenza=%.1fs success=%s",
+        turn, tool_name, player_action[:40], elapsed, result.get("success", True),
+    )
+
     return {
         "turn": turn,
         "action": player_action,

src/web/server.py

@@ -287,9 +287,10 @@ async def index():
 def main():
     logging.basicConfig(
         level=logging.INFO,
-        format="%(asctime)s [%(levelname)s] %(name)s: %(message)s",
+        format="%(asctime)s [%(levelname)-5s] %(name)s: %(message)s",
     )
     db.init_db()
+    db.backup_db()
     cfg = load_from_env()
     log.info(
         "DM config: provider=%s model=%s",