From f0dc0669bd353aad1283197d8c500e28b61de08d Mon Sep 17 00:00:00 2001 From: perf3ct Date: Tue, 8 Jul 2025 22:32:32 +0000 Subject: [PATCH] debug(tests): add some debug lines to see why CI is upset --- ...0002_force_recreate_ocr_stats_function.sql | 31 ------- src/main.rs | 83 +++++++++++++++++-- 2 files changed, 78 insertions(+), 36 deletions(-) delete mode 100644 migrations/20250708000002_force_recreate_ocr_stats_function.sql diff --git a/migrations/20250708000002_force_recreate_ocr_stats_function.sql b/migrations/20250708000002_force_recreate_ocr_stats_function.sql deleted file mode 100644 index 7159fdd..0000000 --- a/migrations/20250708000002_force_recreate_ocr_stats_function.sql +++ /dev/null @@ -1,31 +0,0 @@ --- Force recreation of get_ocr_queue_stats function to clear PostgreSQL cache --- DROP and CREATE instead of CREATE OR REPLACE to ensure function cache invalidation - -DROP FUNCTION IF EXISTS get_ocr_queue_stats(); - -CREATE FUNCTION get_ocr_queue_stats() -RETURNS TABLE ( - pending_count BIGINT, - processing_count BIGINT, - failed_count BIGINT, - completed_today BIGINT, - avg_wait_time_minutes DOUBLE PRECISION, - oldest_pending_minutes DOUBLE PRECISION -) AS $$ -BEGIN - RETURN QUERY - SELECT - COUNT(*) FILTER (WHERE status = 'pending') as pending_count, - COUNT(*) FILTER (WHERE status = 'processing') as processing_count, - COUNT(*) FILTER (WHERE status = 'failed' AND attempts >= max_attempts) as failed_count, - -- Get completed_today from documents table instead of ocr_queue - (SELECT COUNT(*)::BIGINT - FROM documents - WHERE ocr_status = 'completed' - AND updated_at >= CURRENT_DATE - AND updated_at < CURRENT_DATE + INTERVAL '1 day') as completed_today, - CAST(AVG(EXTRACT(EPOCH FROM (COALESCE(started_at, NOW()) - created_at))/60) FILTER (WHERE status IN ('processing', 'completed')) AS DOUBLE PRECISION) as avg_wait_time_minutes, - CAST(MAX(EXTRACT(EPOCH FROM (NOW() - created_at))/60) FILTER (WHERE status = 'pending') AS DOUBLE PRECISION) as oldest_pending_minutes - FROM ocr_queue; -END; -$$ LANGUAGE plpgsql; \ No newline at end of file diff --git a/src/main.rs b/src/main.rs index 5b375ac..2fb95eb 100644 --- a/src/main.rs +++ b/src/main.rs @@ -206,11 +206,54 @@ async fn main() -> anyhow::Result<()> { info!("No migrations found"); } + // Enhanced migration execution with detailed logging + info!("🔄 Starting migration execution..."); + + // Check current database migration state + let applied_migrations = sqlx::query_scalar::<_, i64>( + "SELECT version FROM _sqlx_migrations ORDER BY version" + ) + .fetch_all(web_db.get_pool()) + .await + .unwrap_or_default(); + + if !applied_migrations.is_empty() { + info!("📋 {} migrations already applied in database", applied_migrations.len()); + info!("📋 Latest applied migration: {}", applied_migrations.last().unwrap_or(&0)); + } else { + info!("📋 No migrations previously applied - fresh database"); + } + + // List all migrations that will be processed + info!("📝 Migrations to process:"); + for (i, migration) in migrations.migrations.iter().enumerate() { + let status = if applied_migrations.contains(&migration.version) { + "✅ APPLIED" + } else { + "⏳ PENDING" + }; + info!(" {}: {} ({}) [{}]", + i + 1, migration.version, migration.description, status); + } + let result = migrations.run(web_db.get_pool()).await; match result { Ok(_) => { info!("✅ SQLx migrations completed successfully"); + // Verify final migration state + let final_applied = sqlx::query_scalar::<_, i64>( + "SELECT version FROM _sqlx_migrations ORDER BY version" + ) + .fetch_all(web_db.get_pool()) + .await + .unwrap_or_default(); + + info!("📊 Final migration state: {} total applied", final_applied.len()); + if let Some(latest) = final_applied.last() { + info!("📊 Latest migration now: {}", latest); + } + // Verify the get_ocr_queue_stats function has the correct implementation let function_check = sqlx::query_scalar::<_, Option>( r#" @@ -232,11 +275,23 @@ async fn main() -> anyhow::Result<()> { def.chars().take(500).collect::()); // Check if it contains the correct logic from our latest migration - if def.contains("document_stats") && def.contains("ocr_status = 'completed'") { - info!("✅ get_ocr_queue_stats function has correct logic (uses documents table for completed_today)"); + let has_documents_subquery = def.contains("FROM documents") && def.contains("ocr_status = 'completed'"); + let has_old_cte_logic = def.contains("document_stats") || def.contains("queue_stats"); + let has_old_completed_logic = def.contains("completed_at >= CURRENT_DATE"); + + info!("🔍 Function content analysis:"); + info!(" Has documents subquery: {}", has_documents_subquery); + info!(" Has old CTE logic: {}", has_old_cte_logic); + info!(" Has old completed_at logic: {}", has_old_completed_logic); + + if has_documents_subquery && !has_old_completed_logic { + info!("✅ get_ocr_queue_stats function has correct NEW logic (uses documents table subquery)"); + } else if has_old_cte_logic { + error!("❌ get_ocr_queue_stats function still uses CTE logic - should use simple subquery"); + } else if has_old_completed_logic { + error!("❌ get_ocr_queue_stats function still uses old completed_at logic from ocr_queue table"); } else { - error!("❌ get_ocr_queue_stats function still uses old logic - migration may have failed"); - info!("Function uses ocr_queue table instead of documents table for completed_today count"); + error!("❌ get_ocr_queue_stats function has unexpected structure"); } // Test the function execution at startup @@ -260,7 +315,25 @@ async fn main() -> anyhow::Result<()> { } } Err(e) => { - error!("Failed to run SQLx migrations: {}", e); + error!("❌ CRITICAL: SQLx migrations failed!"); + error!("Migration error: {}", e); + + // Get detailed error information + error!("🔍 Migration failure details:"); + error!(" Error type: {}", std::any::type_name_of_val(&e)); + error!(" Error message: {}", e); + + // Try to get the current migration state even after failure + match sqlx::query_scalar::<_, i64>( + "SELECT version FROM _sqlx_migrations ORDER BY version DESC LIMIT 1" + ) + .fetch_optional(web_db.get_pool()) + .await { + Ok(Some(latest)) => error!(" Last successful migration: {}", latest), + Ok(None) => error!(" No migrations were applied successfully"), + Err(table_err) => error!(" Could not read migration table: {}", table_err), + } + return Err(e.into()); } }