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.
This commit is contained in:
2025-11-02 15:41:47 -05:00
parent 8b91c75b32
commit 18bd4d169d
2 changed files with 56 additions and 5 deletions

View File

@@ -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:

View File

@@ -131,31 +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 - 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}")
if is_dev_mode():
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)
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
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)
logger.info("🛑 FastAPI application shutting down...")
print("🔍 DIAGNOSTIC: LIFESPAN SHUTDOWN CALLED")
app = FastAPI(
title="AI-Trader Simulation API",
@@ -520,23 +538,45 @@ 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
if is_dev_mode():
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__":