Add logger with verbosity

app.py

@@ -39,7 +39,7 @@ LANGUAGES = ["English", "French", "German", "Italian", "Russian", "Turkish", "Ch
 
 DEFAULT_MODEL       = MODELS[14][1]
 DEFAULT_LANGUAGE    = "English"
-TRANSLATION_MODEL   = "openai/gpt-4o-mini"
+TRANSLATION_MODEL   = "google/gemma-3-27b-it"
 
 #MODEL        = "deepseek-ai/DeepSeek-V3"   # or e.g. "openai/gpt-4o-mini"
 #MODEL       = "Qwen/Qwen3-235B-A22B-Instruct-2507"
@@ -145,6 +145,7 @@ chatbot = gr.ChatInterface(
 # ── Event handlers ─────────────────────────────────────────────────────────────
 
 def on_character_change(new_char_id: str):
+    logger.info(f"[App] Character change requested → '{new_char_id}'")
     try:
         char = load_character(new_char_id)
     except Exception as e:
@@ -154,6 +155,7 @@ def on_character_change(new_char_id: str):
     role   = char.get("identity", {}).get("role", "")
     greet  = char.get("greeting", "Hello. What do you want?")
     avatar = get_avatar_path(new_char_id)
+    logger.info(f"[App] Character loaded: name='{name}', role='{role}', avatar={'found' if avatar else 'missing'}")
     return (
         new_char_id,
         f"## {name}",
@@ -173,25 +175,32 @@ def apply_persona_fn(name, age, gender, personality, background):
         "personality": personality, "background": background,
     })
     if is_persona_empty(persona):
+        logger.info("[App] Persona applied but all fields empty — no persona active.")
         return persona, "*No persona set.*"
+    logger.info(f"[App] Persona applied: {persona_summary(persona)}")
     return persona, f"*✓ Active: {persona_summary(persona)}*"
 
 
 def clear_persona_fn():
+    logger.info("[App] Persona cleared.")
     # Returns: persona_state, 5 form fields, status
     return get_empty_persona(), "", "", "", "", "", "*Persona cleared.*"
 
 
 def get_suggestions_fn(char_id: str, model_id: str):
+    logger.info(f"[App] Suggestion request: char='{char_id}', model='{model_id}'")
     if not HF_TOKEN:
+        logger.warning("[App] Suggestions skipped — HF_TOKEN not set.")
         return [gr.update(visible=False)] + [gr.update(visible=False)] * 4 + [""] * 4
     recent = load_recent_messages(char_id, max_messages=6)
     if not recent:
+        logger.info("[App] Suggestions skipped — no recent messages.")
         return [gr.update(visible=False)] + [gr.update(visible=False)] * 4 + [""] * 4
     try:
         char   = load_character(char_id)
         client = InferenceClient(token=HF_TOKEN)
         suggestions = generate_suggestions(char, recent, client, model_id)
+        logger.info(f"[App] Suggestions generated: {[s['tone'] for s in suggestions]}")
     except Exception as e:
         logger.error(f"[App] Suggestion error: {e}")
         return [gr.update(visible=False)] + [gr.update(visible=False)] * 4 + [""] * 4
@@ -204,11 +213,13 @@ def get_suggestions_fn(char_id: str, model_id: str):
 
 def save_conversation_fn(char_id: str, persona: dict):
     """Write a save file and return its path for Gradio to serve as download."""
+    logger.info(f"[App] Save requested for char='{char_id}'")
     try:
         path = export_save(char_id, persona)
+        logger.info(f"[App] Save successful → {path}")
         return gr.update(value=path, visible=True), "*✓ Save file ready — click to download.*"
     except Exception as e:
-        logger.error(f"[App] Save failed: {e}")
+        logger.error(f"[App] Save failed: {e}", exc_info=True)
         return gr.update(visible=False), f"*❌ Save failed: {e}*"
 
 
@@ -226,15 +237,18 @@ def load_conversation_fn(file_path, current_char_id: str):
     no_op = [gr.update()] * 12 + [""]
 
     if not file_path:
+        logger.debug("[App] Load called with no file path — skipping.")
         return no_op
 
+    logger.info(f"[App] Load requested: {file_path}")
     try:
         data = import_save(file_path)
         restore_save(data)
     except (ValueError, KeyError) as e:
+        logger.warning(f"[App] Load validation error: {e}")
         return no_op[:-1] + [f"*❌ {e}*"]
     except Exception as e:
-        logger.error(f"[App] Load error: {e}")
+        logger.error(f"[App] Load error: {e}", exc_info=True)
         return no_op[:-1] + [f"*❌ Unexpected error: {type(e).__name__}*"]
 
     char_id = data["character_id"]

engine/chat.py

@@ -62,16 +62,19 @@ def generate_response(
     """
     
     
+    logger.info(f"[Chat] ▶ character='{character_id}' | language='{language}' | model='{model}'")
+
     # ── Load character ─────────────────────────────────────────────────────────
     
     try:
         character = load_character(character_id)
+        logger.debug(f"[Chat] Character loaded: '{character.get('name', character_id)}'")
     except FileNotFoundError:
         logger.error(f"[Chat] Character not found: {character_id}")
         yield f"*(Character '{character_id}' could not be loaded.)*"
         return
     except Exception as e:
-        logger.error(f"[Chat] Unexpected error loading character: {e}")
+        logger.error(f"[Chat] Unexpected error loading character: {e}", exc_info=True)
         yield "*(Something went wrong loading the character. Check the logs.)*"
         return
 
@@ -79,13 +82,21 @@ def generate_response(
     recent_messages  = load_recent_messages(character_id)
     summary          = load_summary(character_id)
     long_term_memory = load_long_term_memory(character_id)
+    logger.debug(
+        f"[Chat] Memory: {len(recent_messages)} recent messages | "
+        f"summary={'yes' if summary else 'no'} | "
+        f"long_term={len(long_term_memory)} entries"
+    )
 
     # ── Translation mode? ──────────────────────────────────────────────────────
     use_translation = language.strip().lower() != "english" and bool(translation_model)
+    logger.info(f"[Chat] Translation mode: {'ON → ' + translation_model if use_translation else 'OFF'}")
 
     if use_translation:
         # Translate user message → English before sending to main model
+        logger.debug(f"[Chat] Translating user message: {message[:80]!r}")
         en_message = translate_to_english(message, language, client, translation_model)
+        logger.debug(f"[Chat] User message (EN): {en_message[:80]!r}")
         prompt_language = "English"   # main model always responds in English
     else:
         en_message      = message
@@ -101,8 +112,13 @@ def generate_response(
         current_message=en_message,
         language=prompt_language,
     )
+    logger.debug(
+        f"[Chat] Prompt built: {len(messages[0]['content'])} chars system | "
+        f"{len(messages)} total messages"
+    )
 
     # ── LLM call ──────────────────────────────────────────────────────────────
+    logger.info(f"[Chat] LLM call: model='{model}' max_tokens={max_tokens} temp={temperature:.2f} top_p={top_p:.2f}")
     
     raw_response = ""
 
@@ -137,25 +153,31 @@ def generate_response(
                 yield raw_response
 
     except Exception as e:
-        logger.error(f"[Chat] LLM error: {e}")
+        logger.error(f"[Chat] LLM error: {e}", exc_info=True)
         error_note = "\n\n*(The model did not respond. Please try again.)*"
         yield (raw_response + error_note) if raw_response else error_note.strip()
         return
 
+    logger.info(f"[Chat] Stream complete: {len(raw_response)} chars generated")
+
     # ── Post-stream ────────────────────────────────────────────────────────────
     # Memory always stores English (so main model gets consistent context)
     try:
         append_message(character_id, "user",      en_message)
         append_message(character_id, "assistant", raw_response)
+        logger.debug(f"[Chat] Memory saved: user + assistant turn appended")
     except Exception as e:
-        logger.error(f"[Chat] Memory save failed: {e}")
+        logger.error(f"[Chat] Memory save failed: {e}", exc_info=True)
 
     # ── Translate response → user's language, format, yield ───────────────────
     if use_translation:
+        logger.debug(f"[Chat] Translating response → {language} ({len(raw_response)} chars)")
         final_text = translate_from_english(raw_response, language, client, translation_model)
     else:
         final_text = raw_response
 
     segments  = parse_response(final_text)
+    logger.debug(f"[Chat] Parser: {len(segments)} segments → {[s['type'] for s in segments]}")
     formatted = segments_to_markdown(segments)
+    logger.info(f"[Chat] ✓ Response ready: {len(formatted)} chars, {len(segments)} segments")
     yield formatted

engine/memory.py

@@ -58,13 +58,17 @@ def load_recent_messages(character_id: str, max_messages: int = MAX_RECENT) -> l
     """Load the last `max_messages` conversation turns for a character."""
     path = os.path.join(_memory_dir(character_id), "recent_messages.json")
     data = _load(path, {"messages": []})
-    return data.get("messages", [])[-max_messages:]
+    messages = data.get("messages", [])[-max_messages:]
+    logger.debug(f"[Memory] Loaded {len(messages)} recent messages for '{character_id}'")
+    return messages
 
 
 def save_recent_messages(character_id: str, messages: list[dict]) -> None:
     """Overwrite the recent messages file (trims to MAX_RECENT)."""
     path = os.path.join(_memory_dir(character_id), "recent_messages.json")
-    _save(path, {"messages": messages[-MAX_RECENT:]})
+    trimmed = messages[-MAX_RECENT:]
+    _save(path, {"messages": trimmed})
+    logger.debug(f"[Memory] Saved {len(trimmed)} recent messages for '{character_id}'")
 
 
 def append_message(character_id: str, role: str, content: str) -> None:
@@ -72,6 +76,7 @@ def append_message(character_id: str, role: str, content: str) -> None:
     messages = load_recent_messages(character_id, max_messages=MAX_RECENT)
     messages.append({"role": role, "content": content})
     save_recent_messages(character_id, messages)
+    logger.debug(f"[Memory] Appended [{role}] message for '{character_id}': {content[:60]!r}")
 
 
 # ── Summary ────────────────────────────────────────────────────────────────────
@@ -80,13 +85,16 @@ def load_summary(character_id: str) -> str:
     """Load the rolling conversation summary string for a character."""
     path = os.path.join(_memory_dir(character_id), "summary.json")
     data = _load(path, {"summary": ""})
-    return data.get("summary", "")
+    summary = data.get("summary", "")
+    logger.debug(f"[Memory] Summary for '{character_id}': {len(summary)} chars")
+    return summary
 
 
 def save_summary(character_id: str, summary: str) -> None:
     """Overwrite the conversation summary for a character."""
     path = os.path.join(_memory_dir(character_id), "summary.json")
     _save(path, {"summary": summary, "updated_at": _now()})
+    logger.info(f"[Memory] Summary saved for '{character_id}': {len(summary)} chars")
 
 
 # ── Long-term memory ───────────────────────────────────────────────────────────
@@ -95,13 +103,16 @@ def load_long_term_memory(character_id: str) -> list[dict]:
     """Load all long-term memory entries for a character."""
     path = os.path.join(_memory_dir(character_id), "long_term_memory.json")
     data = _load(path, {"memories": []})
-    return data.get("memories", [])
+    memories = data.get("memories", [])
+    logger.debug(f"[Memory] Loaded {len(memories)} long-term memories for '{character_id}'")
+    return memories
 
 
 def save_long_term_memory(character_id: str, memories: list[dict]) -> None:
     """Overwrite the long-term memory file for a character."""
     path = os.path.join(_memory_dir(character_id), "long_term_memory.json")
     _save(path, {"memories": memories})
+    logger.info(f"[Memory] Saved {len(memories)} long-term memories for '{character_id}'")
 
 
 def add_memory(character_id: str, content: str, importance: str = "medium") -> None:
@@ -112,4 +123,5 @@ def add_memory(character_id: str, content: str, importance: str = "medium") -> N
         "importance": importance,
         "created_at": _now(),
     })
-    save_long_term_memory(character_id, memories)
+    save_long_term_memory(character_id, memories)
+    logger.info(f"[Memory] New long-term memory [{importance}] for '{character_id}': {content[:80]!r}")

engine/parser.py

@@ -20,9 +20,12 @@ Example:
     # ]
 """
 
+import logging
 import re
 from typing import TypedDict
 
+logger = logging.getLogger(__name__)
+
 
 # Matches:
 #   <action>...</action>
@@ -87,6 +90,8 @@ def parse_response(text: str) -> list[Segment]:
                 "content": part,
             })
 
+    type_counts = {t: sum(1 for s in segments if s["type"] == t) for t in ("dialogue", "action", "thought")}
+    logger.debug(f"[Parser] {len(text)} chars → {len(segments)} segments {type_counts}")
     return segments
 
 

engine/prompt_builder.py

@@ -305,4 +305,10 @@ def build_messages(
     messages.extend(recent_messages)
     messages.append({"role": "user", "content": current_message})
 
+    logger.debug(
+        f"[PromptBuilder] Built: {len(system_content)} chars system | "
+        f"{len(system_sections)} sections | "
+        f"{len(recent_messages)} history turns | "
+        f"language='{language}'"
+    )
     return messages

engine/suggestions.py

@@ -85,11 +85,13 @@ def generate_suggestions(
         client:          Initialised HuggingFace InferenceClient.
         model:           HuggingFace model string.
     """
+    name = character.get("name", "the character")
+    logger.info(f"[Suggestions] ▶ character='{name}' | model='{model}' | {len(recent_messages)} recent messages")
+
     try:
         system_prompt = _load_prompt()
 
         # Prepend a brief character context so suggestions fit the scene
-        name        = character.get("name", "the character")
         personality = character.get("personality", [])
         char_ctx    = f"The user is talking with {name}"
         if personality:
@@ -110,7 +112,9 @@ def generate_suggestions(
         )
 
         raw = response.choices[0].message.content
-        return _parse(raw)
+        suggestions = _parse(raw)
+        logger.info(f"[Suggestions] ✓ Generated: {[s['tone'] for s in suggestions]}")
+        return suggestions
 
     except Exception as e:
         logger.warning(f"[Suggestions] Generation failed ({e}). Using fallback.")

engine/translator.py

@@ -10,6 +10,7 @@ Formatting rules:
 """
 
 import logging
+import time
 from huggingface_hub import InferenceClient
 
 logger = logging.getLogger(__name__)
@@ -42,8 +43,11 @@ def translate_to_english(
     Returns the original text unchanged if already English or on any failure.
     """
     if not text.strip() or source_language.strip().lower() == "english":
+        logger.debug("[Translator] to_english skipped (already English or empty).")
         return text
 
+    logger.info(f"[Translator] ▶ {source_language}→EN | model='{model}' | {len(text)} chars")
+    start = time.time()
     try:
         response = client.chat_completion(
             messages=[
@@ -56,10 +60,12 @@ def translate_to_english(
             temperature=0.1,
         )
         result = response.choices[0].message.content.strip()
-        logger.info(f"[Translator] {source_language}→EN: {text[:60]!r} → {result[:60]!r}")
+        elapsed = time.time() - start
+        logger.info(f"[Translator] ✓ {source_language}→EN | {elapsed:.1f}s | {len(result)} chars")
+        logger.debug(f"[Translator] {source_language}→EN: {text[:80]!r} → {result[:80]!r}")
         return result
     except Exception as e:
-        logger.warning(f"[Translator] to_english failed ({e}), keeping original.")
+        logger.error(f"[Translator] to_english FAILED | model='{model}' | error: {e}", exc_info=True)
         return text
 
 
@@ -74,8 +80,11 @@ def translate_from_english(
     Returns the original text unchanged if target is English or on any failure.
     """
     if not text.strip() or target_language.strip().lower() == "english":
+        logger.debug("[Translator] from_english skipped (target is English or empty).")
         return text
 
+    logger.info(f"[Translator] ▶ EN→{target_language} | model='{model}' | {len(text)} chars")
+    start = time.time()
     try:
         system = _FROM_EN.format(language=target_language)
         response = client.chat_completion(
@@ -89,8 +98,10 @@ def translate_from_english(
             temperature=0.1,
         )
         result = response.choices[0].message.content.strip()
-        logger.info(f"[Translator] EN→{target_language}: {text[:60]!r} → {result[:60]!r}")
+        elapsed = time.time() - start
+        logger.info(f"[Translator] ✓ EN→{target_language} | {elapsed:.1f}s | {len(result)} chars")
+        logger.debug(f"[Translator] EN→{target_language}: {text[:80]!r} → {result[:80]!r}")
         return result
     except Exception as e:
-        logger.warning(f"[Translator] from_english failed ({e}), keeping original.")
+        logger.error(f"[Translator] from_english FAILED | model='{model}' | error: {e}", exc_info=True)
         return text