debug: add comprehensive diagnostic logging for database initialization

Following systematic debugging methodology after 5 failed fix attempts.
Adding extensive print-based diagnostics to trace execution flow in Docker.

Instrumentation added to:
- api/main.py: Module import, app creation, lifespan function, module-level init
- api/database.py: initialize_dev_database() entry/exit and decision points

This diagnostic version will help identify:
1. Whether module-level code executes in Docker
2. Which initialization layer is failing
3. Database paths being resolved
4. Environment variable values

Tests confirmed passing with diagnostic logging.

api/database.py

@@ -244,24 +244,35 @@ def initialize_dev_database(db_path: str = "data/trading_dev.db") -> None:
     Args:
         db_path: Path to dev database file
     """
+    print(f"🔍 DIAGNOSTIC: initialize_dev_database() CALLED with db_path={db_path}")
     from tools.deployment_config import should_preserve_dev_data
 
-    if should_preserve_dev_data():
+    preserve = should_preserve_dev_data()
+    print(f"🔍 DIAGNOSTIC: should_preserve_dev_data() returned: {preserve}")
+
+    if preserve:
         print(f"ℹ️  PRESERVE_DEV_DATA=true, keeping existing dev database: {db_path}")
         # Ensure schema exists even if preserving data
-        if not Path(db_path).exists():
+        db_exists = Path(db_path).exists()
+        print(f"🔍 DIAGNOSTIC: Database exists check: {db_exists}")
+        if not db_exists:
             print(f"📁 Dev database doesn't exist, creating: {db_path}")
             initialize_database(db_path)
+        print(f"🔍 DIAGNOSTIC: initialize_dev_database() RETURNING (preserve mode)")
         return
 
     # Delete existing dev database
-    if Path(db_path).exists():
+    db_exists = Path(db_path).exists()
+    print(f"🔍 DIAGNOSTIC: Database exists (before deletion): {db_exists}")
+    if db_exists:
         print(f"🗑️  Removing existing dev database: {db_path}")
         Path(db_path).unlink()
+        print(f"🔍 DIAGNOSTIC: Database deleted successfully")
 
     # Create fresh dev database
     print(f"📁 Creating fresh dev database: {db_path}")
     initialize_database(db_path)
+    print(f"🔍 DIAGNOSTIC: initialize_dev_database() COMPLETED successfully")
 
 
 def cleanup_dev_database(db_path: str = "data/trading_dev.db", data_path: str = "./data/dev_agent_data") -> None:

api/main.py

@@ -131,23 +131,49 @@ def create_app(
     @asynccontextmanager
     async def lifespan(app: FastAPI):
         """Initialize database on startup, cleanup on shutdown if needed"""
+        print("=" * 80)
+        print("🔍 DIAGNOSTIC: LIFESPAN FUNCTION CALLED!")
+        print("=" * 80)
+
         from tools.deployment_config import is_dev_mode, get_db_path
         from api.database import initialize_dev_database, initialize_database
 
-        # Startup
-        if is_dev_mode():
+        # Startup - use closure to access db_path from create_app scope
+        logger.info("🚀 FastAPI application starting...")
+        logger.info("📊 Initializing database...")
+        print(f"🔍 DIAGNOSTIC: Lifespan - db_path from closure: {db_path}")
+
+        deployment_mode = is_dev_mode()
+        print(f"🔍 DIAGNOSTIC: Lifespan - is_dev_mode() returned: {deployment_mode}")
+
+        if deployment_mode:
             # Initialize dev database (reset unless PRESERVE_DEV_DATA=true)
-            dev_db_path = get_db_path(app.state.db_path)
+            logger.info("  🔧 DEV mode detected - initializing dev database")
+            print("🔍 DIAGNOSTIC: Lifespan - DEV mode detected")
+            dev_db_path = get_db_path(db_path)
+            print(f"🔍 DIAGNOSTIC: Lifespan - Resolved dev database path: {dev_db_path}")
+            print(f"🔍 DIAGNOSTIC: Lifespan - About to call initialize_dev_database({dev_db_path})")
             initialize_dev_database(dev_db_path)
+            print(f"🔍 DIAGNOSTIC: Lifespan - initialize_dev_database() completed")
             log_dev_mode_startup_warning()
         else:
             # Ensure production database schema exists
-            initialize_database(app.state.db_path)
+            logger.info("  🏭 PROD mode - ensuring database schema exists")
+            print("🔍 DIAGNOSTIC: Lifespan - PROD mode detected")
+            print(f"🔍 DIAGNOSTIC: Lifespan - About to call initialize_database({db_path})")
+            initialize_database(db_path)
+            print(f"🔍 DIAGNOSTIC: Lifespan - initialize_database() completed")
+
+        logger.info("✅ Database initialized")
+        logger.info("🌐 API server ready to accept requests")
+        print("🔍 DIAGNOSTIC: Lifespan - Startup complete, yielding control")
+        print("=" * 80)
 
         yield
 
         # Shutdown (if needed in future)
-        pass
+        logger.info("🛑 FastAPI application shutting down...")
+        print("🔍 DIAGNOSTIC: LIFESPAN SHUTDOWN CALLED")
 
     app = FastAPI(
         title="AI-Trader Simulation API",
@@ -512,13 +538,51 @@ def create_app(
 
 
 # Create default app instance
+print("=" * 80)
+print("🔍 DIAGNOSTIC: Module api.main is being imported/executed")
+print("=" * 80)
+
 app = create_app()
+print(f"🔍 DIAGNOSTIC: create_app() completed, app object created: {app}")
+
+# Ensure database is initialized when module is loaded
+# This handles cases where lifespan might not be triggered properly
+print("🔍 DIAGNOSTIC: Starting module-level database initialization check...")
+logger.info("🔧 Module-level database initialization check...")
+
+from tools.deployment_config import is_dev_mode, get_db_path
+from api.database import initialize_dev_database, initialize_database
+
+_db_path = app.state.db_path
+print(f"🔍 DIAGNOSTIC: app.state.db_path = {_db_path}")
+
+deployment_mode = is_dev_mode()
+print(f"🔍 DIAGNOSTIC: is_dev_mode() returned: {deployment_mode}")
+
+if deployment_mode:
+    print("🔍 DIAGNOSTIC: DEV mode detected - initializing dev database at module load")
+    logger.info("  🔧 DEV mode - initializing dev database at module load")
+    _dev_db_path = get_db_path(_db_path)
+    print(f"🔍 DIAGNOSTIC: Resolved dev database path: {_dev_db_path}")
+    print(f"🔍 DIAGNOSTIC: About to call initialize_dev_database({_dev_db_path})")
+    initialize_dev_database(_dev_db_path)
+    print(f"🔍 DIAGNOSTIC: initialize_dev_database() completed successfully")
+else:
+    print("🔍 DIAGNOSTIC: PROD mode - ensuring database exists at module load")
+    logger.info("  🏭 PROD mode - ensuring database exists at module load")
+    print(f"🔍 DIAGNOSTIC: About to call initialize_database({_db_path})")
+    initialize_database(_db_path)
+    print(f"🔍 DIAGNOSTIC: initialize_database() completed successfully")
+
+print("🔍 DIAGNOSTIC: Module-level database initialization complete")
+logger.info("✅ Module-level database initialization complete")
+print("=" * 80)
 
 
 if __name__ == "__main__":
     import uvicorn
 
-    # Note: Database initialization happens in startup_event()
-    # DEV mode warning will be displayed there as well
+    # Note: Database initialization happens in lifespan AND at module load
+    # for maximum reliability
 
     uvicorn.run(app, host="0.0.0.0", port=8080)

entrypoint.sh

@@ -36,12 +36,7 @@ fi
 
 echo "✅ Environment variables validated"
 
-# Step 1: Initialize database
-echo "📊 Initializing database..."
-python -c "from api.database import initialize_database; initialize_database('data/jobs.db')"
-echo "✅ Database initialized"
-
-# Step 2: Merge and validate configuration
+# Step 1: Merge and validate configuration
 echo "🔧 Merging and validating configuration..."
 python -c "from tools.config_merger import merge_and_validate; merge_and_validate()" || {
     echo "❌ Configuration validation failed"
@@ -50,7 +45,7 @@ python -c "from tools.config_merger import merge_and_validate; merge_and_validat
 export CONFIG_PATH=/tmp/runtime_config.json
 echo "✅ Configuration validated and merged"
 
-# Step 3: Start MCP services in background
+# Step 2: Start MCP services in background
 echo "🔧 Starting MCP services..."
 cd /app
 python agent_tools/start_mcp_services.py &
@@ -59,11 +54,11 @@ MCP_PID=$!
 # Setup cleanup trap before starting uvicorn
 trap "echo '🛑 Stopping services...'; kill $MCP_PID 2>/dev/null; exit 0" EXIT SIGTERM SIGINT
 
-# Step 4: Wait for services to initialize
+# Step 3: Wait for services to initialize
 echo "⏳ Waiting for MCP services to start..."
 sleep 3
 
-# Step 5: Start FastAPI server with uvicorn (this blocks)
+# Step 4: Start FastAPI server with uvicorn (this blocks)
 # Note: Container always uses port 8080 internally
 # The API_PORT env var only affects the host port mapping in docker-compose.yml
 echo "🌐 Starting FastAPI server on port 8080..."