debug: logs in search.py and main.py

main.py

@@ -64,6 +64,26 @@ async def lifespan(_app):
         )
         print("[lifespan] Basic initialization complete")
         
+        # Verify the server is ready to accept connections
+        import socket
+        import os
+        
+        def check_port_available(port):
+            s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
+            try:
+                s.bind(('0.0.0.0', port))
+                s.close()
+                return False  # Port is available, not in use
+            except:
+                return True  # Port is in use, not available
+                
+        # Check if the port is in use
+        port = int(os.environ.get("PORT", 8000))
+        if check_port_available(port):
+            print(f"[lifespan] ✅ Server port {port} is active, ready to accept connections")
+        else:
+            print(f"[lifespan] ⚠️ Warning: Server port {port} is not bound yet!")
+
         # Add a delay before starting the intensive search indexing
         print("[lifespan] Waiting for system stabilization before search indexing...")
         await asyncio.sleep(10)  # 10-second delay to let the system stabilize
@@ -85,6 +105,7 @@ async def initialize_search_index_background():
         print("[search] Starting background search indexing process")
         from services.db import fetch_all_shouts
         
+        print("[search] About to fetch all shouts for indexing")
         # Get total count first (optional)
         all_shouts = await fetch_all_shouts()
         total_count = len(all_shouts) if all_shouts else 0
@@ -94,8 +115,19 @@ async def initialize_search_index_background():
         print("[search] Beginning background search index initialization...")
         await initialize_search_index(all_shouts)
         print("[search] Background search index initialization complete")
+        
+        # Perform a test search to verify indexing worked
+        try:
+            print("[search] Running test search to verify index...")
+            from services.search import search_text
+            test_results = await search_text("test", 3)
+            print(f"[search] Test search complete with {len(test_results)} results")
+        except Exception as test_error:
+            print(f"[search] Test search error: {str(test_error)}")
     except Exception as e:
         print(f"[search] Error in background search indexing: {str(e)}")
+        import traceback
+        print(f"[search] Search indexing traceback: {traceback.format_exc()}")
 
 # Создаем экземпляр GraphQL
 graphql_app = GraphQL(schema, debug=True)

services/search.py

@@ -864,30 +864,54 @@ async def get_author_search_count(text: str):
 async def initialize_search_index(shouts_data):
     """Initialize search index with existing data during application startup"""
     if not SEARCH_ENABLED:
+        logger.info("Search indexing skipped - search is disabled")
         return
 
     if not shouts_data:
+        logger.info("Search indexing skipped - no shouts data available")
         return
 
-    info = await search_service.info()
-    if info.get("status") in ["error", "unavailable", "disabled"]:
+    # Add a timeout for the search information request
+    try:
+        info_future = search_service.info()
+        info = await asyncio.wait_for(info_future, timeout=15.0)  # 15 second timeout
+        
+        if info.get("status") in ["error", "unavailable", "disabled"]:
+            logger.error(f"Search indexing aborted - search service unavailable: {info}")
+            return
+            
+        logger.info(f"Search indexing proceeding with index stats: {info.get('index_stats', {})}")
+    except asyncio.TimeoutError:
+        logger.error("Search service info request timed out after 15 seconds")
+        return
+    except Exception as e:
+        logger.error(f"Error getting search service info: {str(e)}")
         return
 
     index_stats = info.get("index_stats", {})
     indexed_doc_count = index_stats.get("total_count", 0)
     
-    index_status = await search_service.check_index_status()
-    if index_status.get("status") == "inconsistent":
-        problem_ids = index_status.get("consistency", {}).get(
-            "null_embeddings_sample", []
-        )
+    try:
+        index_status_future = search_service.check_index_status()
+        index_status = await asyncio.wait_for(index_status_future, timeout=15.0)
         
-        if problem_ids:
-            problem_docs = [
-                shout for shout in shouts_data if str(shout.id) in problem_ids
-            ]
-            if problem_docs:
-                await search_service.bulk_index(problem_docs)
+        if index_status.get("status") == "inconsistent":
+            logger.warning("Found inconsistent search index state")
+            problem_ids = index_status.get("consistency", {}).get(
+                "null_embeddings_sample", []
+            )
+
+            if problem_ids:
+                problem_docs = [
+                    shout for shout in shouts_data if str(shout.id) in problem_ids
+                ]
+                if problem_docs:
+                    logger.info(f"Reindexing {len(problem_docs)} inconsistent documents")
+                    await search_service.bulk_index(problem_docs)
+    except asyncio.TimeoutError:
+        logger.error("Search index status check timed out after 15 seconds")
+    except Exception as e:
+        logger.error(f"Error checking search index status: {str(e)}")
 
     # Only consider shouts with body content for body verification
     def has_body_content(shout):
@@ -937,14 +961,25 @@ async def initialize_search_index(shouts_data):
     try:
         test_query = "test"
         # Use body search since that's most likely to return results
-        test_results = await search_text(test_query, 5)
+        logger.info(f"Running test search with query: '{test_query}'")
+        try:
+            search_future = search_text(test_query, 5)
+            test_results = await asyncio.wait_for(search_future, timeout=15.0)
             
-        if test_results:
-            categories = set()
-            for result in test_results:
-                result_id = result.get("id")
-                matching_shouts = [s for s in shouts_data if str(s.id) == result_id]
-                if matching_shouts and hasattr(matching_shouts[0], "category"):
-                    categories.add(getattr(matching_shouts[0], "category", "unknown"))
+            if test_results:
+                logger.info(f"Test search successful! Found {len(test_results)} results")
+                categories = set()
+                for result in test_results:
+                    result_id = result.get("id")
+                    matching_shouts = [s for s in shouts_data if str(s.id) == result_id]
+                    if matching_shouts and hasattr(matching_shouts[0], "category"):
+                        categories.add(getattr(matching_shouts[0], "category", "unknown"))
+                logger.info(f"Search test complete: found categories {categories}")
+            else:
+                logger.warning("Test search completed but returned no results")
+        except asyncio.TimeoutError:
+            logger.error("Test search timed out after 15 seconds")
+        except Exception as test_error:
+            logger.error(f"Error during test search: {str(test_error)}")
     except Exception as e:
-        pass
+        logger.error(f"Error in final search verification: {str(e)}")