debug: logs in steps in precahing

cache/precache.py

@@ -97,6 +97,10 @@ async def precache_data():
                 await redis.execute("HSET", key, *value)
             logger.info(f"redis hash '{key}' was restored")
 
+        # Set a start time to track total execution time
+        import time
+        start_time = time.time()
+
         with local_session() as session:
             # topics
             q = select(Topic).where(Topic.community == 1)
@@ -153,8 +157,19 @@ async def precache_data():
                 import traceback
                 logger.error(f"Error processing authors: {author_exc}")
                 logger.error(traceback.format_exc())
+                
+        # Calculate total execution time and log it
+        import time
+        end_time = time.time()
+        execution_time = end_time - start_time
+        logger.info(f"Total precache execution time: {execution_time:.2f} seconds")
+        
+        # Double-check that we're actually returning and not getting stuck somewhere
+        logger.info("Precache operation complete - returning to caller")
+        return True
     except Exception as exc:
         import traceback
 
         traceback.print_exc()
         logger.error(f"Error in precache_data: {exc}")
+        return False

main.py

@@ -3,6 +3,7 @@ import os
 import sys
 from importlib import import_module
 from os.path import exists
+from datetime import datetime
 
 from ariadne import load_schema_from_path, make_executable_schema
 from ariadne.asgi import GraphQL
@@ -35,8 +36,15 @@ async def start():
                 f.write(str(os.getpid()))
     print(f"[main] process started in {MODE} mode")
 
+# Disable search service if it's causing problems
+DISABLE_SEARCH = os.environ.get("DISABLE_SEARCH", "false").lower() in ["true", "1", "yes"]
+
 async def check_search_service():
     """Check if search service is available and log result"""
+    if DISABLE_SEARCH:
+        print("[INFO] Search service checks disabled via environment variable")
+        return {"status": "disabled", "message": "Search disabled via environment variable"}
+        
     try:
         info_task = search_service.info()
         info = await asyncio.wait_for(info_task, timeout=10.0)  # 10 second timeout
@@ -45,11 +53,14 @@ async def check_search_service():
             print(f"[WARNING] Search service unavailable: {info.get('message', 'unknown reason')}")
         else:
             print(f"[INFO] Search service is available: {info}")
+        return info
     except asyncio.TimeoutError:
         print("[WARNING] Search service check timed out after 10 seconds")
+        return {"status": "timeout", "message": "Search service check timed out"}
     except Exception as e:
         print(f"[WARNING] Error checking search service: {str(e)}")
         print("[INFO] Continuing startup with search service in degraded mode")
+        return {"status": "error", "message": str(e)}
 
 
 # indexing DB data
@@ -72,10 +83,18 @@ async def lifespan(_app):
             
         try:
             print("[lifespan] Starting precache operation...")
-            await precache_data()
-            print("[lifespan] Precache completed successfully")
+            # Add a timeout to precache_data to ensure it doesn't hang
+            try:
+                precache_task = precache_data()
+                await asyncio.wait_for(precache_task, timeout=60)  # 1 minute timeout
+                print("[lifespan] Precache completed successfully")
+            except asyncio.TimeoutError:
+                print("[lifespan] WARNING: Precache operation timed out after 60 seconds")
+                print("[lifespan] Continuing server startup despite precache timeout")
         except Exception as e:
             print(f"[lifespan] Error during precache: {e}")
+            import traceback
+            print(f"[lifespan] Precache error traceback: {traceback.format_exc()}")
             
         try:
             print("[lifespan] Initializing ViewedStorage...")
@@ -141,8 +160,13 @@ async def lifespan(_app):
         # Start search indexing as a background task with lower priority
         try:
             print("[lifespan] Creating search indexing background task...")
-            asyncio.create_task(initialize_search_index_background())
-            print("[lifespan] Search indexing task scheduled successfully")
+            if DISABLE_SEARCH:
+                print("[lifespan] Search indexing skipped - search is disabled via environment variable")
+            else:
+                # Use a new dedicated task group for search
+                search_task = asyncio.create_task(initialize_search_index_background())
+                # Don't wait for it to complete, let it run in the background
+                print("[lifespan] Search indexing task scheduled successfully")
         except Exception as e:
             print(f"[lifespan] Error scheduling search indexing task: {e}")
 
@@ -240,7 +264,14 @@ app = Starlette(
         Route("/", graphql_handler, methods=["GET", "POST"]),
         Route("/new-author", WebhookEndpoint),
         # Health check endpoint
-        Route("/health", lambda request: JSONResponse({"status": "healthy"}), methods=["GET"]),
+        Route("/health", lambda request: JSONResponse({"status": "healthy", "time": datetime.now().isoformat()}), methods=["GET"]),
+        # Debug endpoint to get server status
+        Route("/debug", lambda request: JSONResponse({
+            "status": "running", 
+            "search_disabled": DISABLE_SEARCH,
+            "mode": MODE,
+            "time": datetime.now().isoformat()
+        }), methods=["GET"]),
     ],
     lifespan=lifespan,
     debug=True,