Ultra-robust chatbot v3.0 with conversation memory and extensive logging

app.py

@@ -1,22 +1,64 @@
-# app.py - Ollama-Only Chatbot
+# app.py - ULTRA-ROBUST Ollama Chatbot with MAXIMUM Logging
 import gradio as gr
 import requests
 import logging
 import sys
+import traceback
+import json
+from datetime import datetime
 
 # ============================================================================
-#                    LOGGING SETUP
+#                    ULTRA-DETAILED LOGGING SYSTEM
 # ============================================================================
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(asctime)s | %(levelname)-8s | %(message)s",
-    handlers=[logging.StreamHandler(sys.stdout)]
-)
-logger = logging.getLogger("ChatbotBrain")
+class ColoredFormatter(logging.Formatter):
+    """Custom formatter with colors for terminal output."""
+    COLORS = {
+        'DEBUG': '\033[94m',     # Blue
+        'INFO': '\033[92m',      # Green  
+        'WARNING': '\033[93m',   # Yellow
+        'ERROR': '\033[91m',     # Red
+        'CRITICAL': '\033[95m',  # Magenta
+        'RESET': '\033[0m'       # Reset
+    }
+    
+    def format(self, record):
+        color = self.COLORS.get(record.levelname, self.COLORS['RESET'])
+        reset = self.COLORS['RESET']
+        record.levelname = f"{color}{record.levelname:8}{reset}"
+        return super().format(record)
+
+# Configure logging
+handler = logging.StreamHandler(sys.stdout)
+handler.setFormatter(ColoredFormatter(
+    "%(asctime)s | %(levelname)s | [%(funcName)s:%(lineno)d] %(message)s"
+))
+logger = logging.getLogger("CHATBOT")
+logger.setLevel(logging.DEBUG)
+logger.addHandler(handler)
+logger.propagate = False
+
+# Silence noisy libraries
+logging.getLogger("httpx").setLevel(logging.WARNING)
+logging.getLogger("httpcore").setLevel(logging.WARNING)
+logging.getLogger("gradio").setLevel(logging.WARNING)
+
+def banner(text):
+    logger.info("=" * 70)
+    logger.info(f"  {text}")
+    logger.info("=" * 70)
 
-logger.info("=" * 60)
-logger.info("  OLLAMA CHATBOT STARTING")
-logger.info("=" * 60)
+def section(text):
+    logger.info("-" * 50)
+    logger.info(f"  >> {text}")
+    logger.info("-" * 50)
+
+# ============================================================================
+#                    STARTUP
+# ============================================================================
+banner("OLLAMA CHATBOT v3.0 - ULTRA LOGGING MODE")
+logger.info(f"Timestamp: {datetime.now().isoformat()}")
+logger.info(f"Python: {sys.version}")
+logger.info(f"Gradio: {gr.__version__}")
 
 # ============================================================================
 #                    OLLAMA CONFIGURATION
@@ -24,87 +66,227 @@ logger.info("=" * 60)
 OLLAMA_URL = "http://localhost:11434"
 MODEL = "llama3.2:3b"
 
-# Check Ollama connection
-logger.info(f"Checking Ollama at {OLLAMA_URL}...")
+section("OLLAMA CONNECTION TEST")
 try:
+    logger.info(f"Connecting to {OLLAMA_URL}...")
     response = requests.get(f"{OLLAMA_URL}/api/tags", timeout=5)
+    logger.info(f"Status Code: {response.status_code}")
+    
     if response.status_code == 200:
         models = [m["name"] for m in response.json().get("models", [])]
-        logger.info(f"Ollama connected! Found {len(models)} models")
+        logger.info(f"SUCCESS! Found {len(models)} models:")
+        for m in models:
+            marker = " <<<< SELECTED" if m == MODEL else ""
+            logger.info(f"    - {m}{marker}")
+        
         if MODEL in models:
-            logger.info(f"Using model: {MODEL}")
+            logger.info(f"Model {MODEL} is available!")
         else:
-            logger.warning(f"Model {MODEL} not found, available: {models[:5]}")
+            logger.warning(f"Model {MODEL} NOT FOUND - may cause errors")
     else:
-        logger.error(f"Ollama returned {response.status_code}")
+        logger.error(f"Ollama error: {response.status_code}")
 except Exception as e:
     logger.error(f"Cannot connect to Ollama: {e}")
-    logger.error("Run: ollama serve")
+    logger.error(">>> RUN: ollama serve <<<")
 
 # ============================================================================
-#                    CHAT FUNCTION
+#                    CONVERSATION MEMORY
 # ============================================================================
+# Store conversation history globally
+conversation_history = []
+
+def log_history():
+    """Log the current conversation history."""
+    logger.debug(f"Current history has {len(conversation_history)} messages:")
+    for i, msg in enumerate(conversation_history):
+        role = msg.get('role', '?')
+        content = msg.get('content', '')[:50]
+        logger.debug(f"  [{i}] {role}: {content}...")
+
+# ============================================================================
+#                    MAIN CHAT FUNCTION
+# ============================================================================
+request_count = 0
+
 def chat_with_ollama(message, history):
-    """Send message to Ollama and get response."""
-    logger.info("-" * 40)
-    logger.info(f"USER: {message}")
-    logger.info(f"History: {len(history)} messages")
+    """
+    Handle chat with ULTRA detailed logging.
     
-    # Build prompt from history (tuple format: [(user, bot), ...])
-    prompt = "You are a helpful AI assistant.\n\n"
-    for user_msg, bot_msg in history:
-        prompt += f"User: {user_msg}\n"
-        if bot_msg:
-            prompt += f"Assistant: {bot_msg}\n"
-    prompt += f"User: {message}\nAssistant:"
+    This function:
+    1. Logs everything about the incoming request
+    2. Builds the prompt from conversation history
+    3. Calls Ollama API
+    4. Logs everything about the response
+    5. Returns the AI's response
+    """
+    global request_count, conversation_history
+    request_count += 1
+    req_id = f"REQ-{request_count:04d}"
     
-    logger.info(f"Sending to Ollama ({MODEL})...")
+    # ===== PHASE 1: LOG INCOMING REQUEST =====
+    section(f"{req_id} - NEW MESSAGE RECEIVED")
+    logger.info(f"[{req_id}] ┌─────────────────────────────────────────")
+    logger.info(f"[{req_id}] │ USER MESSAGE: {message}")
+    logger.info(f"[{req_id}] │ Message Length: {len(message)} chars")
+    logger.info(f"[{req_id}] │ Timestamp: {datetime.now().isoformat()}")
+    logger.info(f"[{req_id}] └─────────────────────────────────────────")
+    
+    # ===== PHASE 2: LOG HISTORY FROM GRADIO =====
+    logger.info(f"[{req_id}] GRADIO HISTORY ANALYSIS:")
+    logger.info(f"[{req_id}]   - Type: {type(history)}")
+    logger.info(f"[{req_id}]   - Length: {len(history) if history else 0}")
+    
+    if history:
+        for i, item in enumerate(history):
+            logger.debug(f"[{req_id}]   - Item[{i}]: type={type(item).__name__}")
+            if isinstance(item, dict):
+                logger.debug(f"[{req_id}]     role={item.get('role')}, content_len={len(str(item.get('content', '')))}")
+            elif isinstance(item, (list, tuple)):
+                logger.debug(f"[{req_id}]     tuple/list with {len(item)} elements")
+            else:
+                logger.debug(f"[{req_id}]     value={str(item)[:100]}")
     
     try:
+        # ===== PHASE 3: BUILD PROMPT =====
+        logger.info(f"[{req_id}] BUILDING PROMPT...")
+        
+        prompt_parts = ["You are a helpful AI assistant. Be friendly and conversational.\n"]
+        
+        # Process history (handle multiple formats)
+        if history:
+            for i, item in enumerate(history):
+                try:
+                    if isinstance(item, dict):
+                        # New Gradio format
+                        role = item.get("role", "unknown")
+                        content = str(item.get("content", ""))
+                        if role == "user":
+                            prompt_parts.append(f"User: {content}")
+                        elif role == "assistant":
+                            prompt_parts.append(f"Assistant: {content}")
+                        logger.debug(f"[{req_id}] Added {role} message ({len(content)} chars)")
+                    elif isinstance(item, (list, tuple)) and len(item) >= 2:
+                        # Old Gradio format
+                        user_msg = str(item[0]) if item[0] else ""
+                        bot_msg = str(item[1]) if item[1] else ""
+                        if user_msg:
+                            prompt_parts.append(f"User: {user_msg}")
+                            logger.debug(f"[{req_id}] Added user message ({len(user_msg)} chars)")
+                        if bot_msg:
+                            prompt_parts.append(f"Assistant: {bot_msg}")
+                            logger.debug(f"[{req_id}] Added assistant message ({len(bot_msg)} chars)")
+                    else:
+                        logger.warning(f"[{req_id}] Skipping unknown history format: {type(item)}")
+                except Exception as e:
+                    logger.error(f"[{req_id}] Error processing history item {i}: {e}")
+        
+        # Add current message
+        prompt_parts.append(f"User: {message}")
+        prompt_parts.append("Assistant:")
+        
+        full_prompt = "\n".join(prompt_parts)
+        
+        logger.info(f"[{req_id}] PROMPT BUILT:")
+        logger.info(f"[{req_id}]   - Total Parts: {len(prompt_parts)}")
+        logger.info(f"[{req_id}]   - Total Length: {len(full_prompt)} chars")
+        logger.debug(f"[{req_id}]   - Full Prompt:\n{full_prompt}")
+        
+        # ===== PHASE 4: CALL OLLAMA =====
+        logger.info(f"[{req_id}] CALLING OLLAMA API...")
+        logger.info(f"[{req_id}]   - URL: {OLLAMA_URL}/api/generate")
+        logger.info(f"[{req_id}]   - Model: {MODEL}")
+        logger.info(f"[{req_id}]   - Stream: False")
+        
+        start_time = datetime.now()
+        
+        payload = {
+            "model": MODEL,
+            "prompt": full_prompt,
+            "stream": False,
+            "options": {
+                "temperature": 0.7,
+                "num_predict": 500
+            }
+        }
+        
+        logger.debug(f"[{req_id}] Request payload: {json.dumps(payload, indent=2)[:500]}...")
+        
         response = requests.post(
             f"{OLLAMA_URL}/api/generate",
-            json={
-                "model": MODEL,
-                "prompt": prompt,
-                "stream": False
-            },
+            json=payload,
             timeout=120
         )
         
+        elapsed = (datetime.now() - start_time).total_seconds()
+        
+        # ===== PHASE 5: LOG RESPONSE =====
+        logger.info(f"[{req_id}] RESPONSE RECEIVED:")
+        logger.info(f"[{req_id}]   - Status Code: {response.status_code}")
+        logger.info(f"[{req_id}]   - Time Elapsed: {elapsed:.2f} seconds")
+        logger.info(f"[{req_id}]   - Response Size: {len(response.text)} bytes")
+        
         if response.status_code == 200:
             result = response.json()
-            text = result.get("response", "")
-            duration = result.get("total_duration", 0) / 1_000_000_000
-            logger.info(f"SUCCESS: Got response in {duration:.1f}s")
-            logger.info(f"AI: {text[:100]}...")
-            return text.strip()
-        else:
-            error = f"Ollama returned {response.status_code}: {response.text}"
-            logger.error(error)
-            return f"Error: {error}"
             
-    except requests.exceptions.ConnectionError:
-        logger.error("Cannot connect to Ollama. Is it running?")
-        return "Error: Cannot connect to Ollama. Run: ollama serve"
+            ai_response = result.get("response", "")
+            total_duration = result.get("total_duration", 0) / 1_000_000_000
+            eval_count = result.get("eval_count", 0)
+            prompt_eval_count = result.get("prompt_eval_count", 0)
+            
+            logger.info(f"[{req_id}] OLLAMA STATS:")
+            logger.info(f"[{req_id}]   - Prompt Tokens: {prompt_eval_count}")
+            logger.info(f"[{req_id}]   - Response Tokens: {eval_count}")
+            logger.info(f"[{req_id}]   - Total Duration: {total_duration:.2f}s")
+            
+            logger.info(f"[{req_id}] AI RESPONSE:")
+            logger.info(f"[{req_id}]   - Length: {len(ai_response)} chars")
+            logger.info(f"[{req_id}]   - Preview: {ai_response[:200]}...")
+            
+            # Save to global history
+            conversation_history.append({"role": "user", "content": message})
+            conversation_history.append({"role": "assistant", "content": ai_response})
+            
+            logger.info(f"[{req_id}] SUCCESS! Returning response to user.")
+            return ai_response.strip()
+        
+        else:
+            logger.error(f"[{req_id}] OLLAMA ERROR!")
+            logger.error(f"[{req_id}]   - Status: {response.status_code}")
+            logger.error(f"[{req_id}]   - Body: {response.text[:500]}")
+            return f"Error: Ollama returned status {response.status_code}\n\nDetails: {response.text[:200]}"
+    
+    except requests.exceptions.ConnectionError as e:
+        logger.error(f"[{req_id}] CONNECTION ERROR!")
+        logger.error(f"[{req_id}]   - Error: {e}")
+        logger.error(f"[{req_id}]   - Is Ollama running? Try: ollama serve")
+        return "Error: Cannot connect to Ollama. Please run: ollama serve"
+    
+    except requests.exceptions.Timeout:
+        logger.error(f"[{req_id}] TIMEOUT!")
+        logger.error(f"[{req_id}]   - Request took longer than 120 seconds")
+        return "Error: Request timed out after 120 seconds"
+    
     except Exception as e:
-        logger.error(f"Error: {e}")
-        return f"Error: {e}"
+        logger.error(f"[{req_id}] UNEXPECTED ERROR!")
+        logger.error(f"[{req_id}]   - Type: {type(e).__name__}")
+        logger.error(f"[{req_id}]   - Error: {e}")
+        logger.error(f"[{req_id}]   - Traceback:\n{traceback.format_exc()}")
+        return f"Error: {type(e).__name__}: {e}\n\nCheck terminal logs for full traceback."
 
 # ============================================================================
 #                    GRADIO UI
 # ============================================================================
-logger.info("Building Gradio UI...")
+section("BUILDING GRADIO UI")
 
 demo = gr.ChatInterface(
     fn=chat_with_ollama,
-    title="CPU Chatbot",
-    description=f"**Powered by Ollama** ({MODEL})\n\nUsing local AI - no cloud required!",
-    examples=["Hello!", "What is Python?", "Tell me a joke"],
+    title="🤖 CPU Chatbot v3.0",
+    description=f"**Powered by Ollama** ({MODEL})\n\n✅ Conversation Memory | 📋 Ultra Logging | 🔧 Local AI",
+    examples=["Hello!", "What is Python?", "Tell me a joke", "Remember my name is Nick"],
 )
 
-logger.info("=" * 60)
-logger.info("  READY - Open http://127.0.0.1:7860")
-logger.info("=" * 60)
+banner("READY! Open http://127.0.0.1:7860")
+logger.info("Watch this terminal for detailed logs of every message!")
 
 if __name__ == "__main__":
     demo.launch()