Update app.py

app.py

@@ -3,8 +3,11 @@ import os
 import logging
 from fastapi import FastAPI, Request, Response
 
-# Set up logging
-logging.basicConfig(level=logging.DEBUG)
+# Set up logging with more detailed configuration
+logging.basicConfig(
+    level=logging.DEBUG,
+    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
+)
 logger = logging.getLogger(__name__)
 
 app = FastAPI()
@@ -13,6 +16,7 @@ proc = None
 @app.on_event("startup")
 async def startup_event():
     global proc
+    logger.info("=== STARTUP EVENT ===")
     # Get the token from an environment variable on the Hugging Face Space
     # This is a more secure way to handle the token
     token = os.environ.get("GITHUB_PERSONAL_ACCESS_TOKEN")
@@ -38,6 +42,7 @@ async def startup_event():
         else:
             logger.warning("Subprocess may have exited immediately with code: %s", proc.returncode)
         asyncio.create_task(log_stderr())
+        logger.info("=== STARTUP COMPLETE ===")
     except Exception as e:
         logger.error("Failed to create subprocess: %s", str(e))
         raise
@@ -45,8 +50,11 @@ async def startup_event():
 async def log_stderr():
     if proc and proc.stderr:
         logger.info("Starting stderr logging task")
-        while not proc.stderr.at_eof():
-            try:
+        while 
+
+<< 35 Characters hidden >>
+
+   try:
                 line = await proc.stderr.readline()
                 if line:
                     logger.debug("github-mcp-server stderr: %s", line.decode().strip())
@@ -58,86 +66,137 @@ async def log_stderr():
 
 @app.post("/")
 async def proxy(request: Request):
+    logger.info("=== NEW REQUEST RECEIVED ===")
+    logger.info("Request method: %s", request.method)
+    logger.info("Request headers: %s", dict(request.headers))
+    
     if not proc or not proc.stdin or not proc.stdout:
-        logger.error("Subprocess not running")
+        logger.error("Subprocess not running - returning 500")
         return Response(status_code=500, content="Subprocess not running")
 
     # Log incoming request
     body = await request.body()
-    logger.info("Received request: %s", body.decode())
-
+    logger.info("Received request body: %s", body.decode())
+    
     # Token verification for debugging
     import requests
-    
     token = os.environ.get("GITHUB_PERSONAL_ACCESS_TOKEN")
     if token:
         try:
+            logger.info("Testing GitHub token with API call...")
             response = requests.get("https://api.github.com/user", headers={"Authorization": f"token {token}"})
+            logger.info("Token verification response status: %s", response.status_code)
             if response.status_code == 200:
                 logger.info("GitHub token verification successful")
             else:
                 logger.error("GitHub token verification failed with status code: %s", response.status_code)
         except Exception as e:
             logger.error("Error verifying GitHub token: %s", str(e))
-    
+    else:
+        logger.warning("No GitHub token found in environment")
 
     # Send to subprocess
-    logger.info("Sending to subprocess...")
-    proc.stdin.write(body)
-    await proc.stdin.drain()
+    logger.info("Sending request to subprocess...")
+    try:
+        proc.stdin.write(body)
+        await proc.stdin.drain()
+        logger.info("Successfully wrote to subprocess stdin")
+    except Exception as e:
+        logger.error("Error writing to subprocess stdin: %s", str(e))
+        return Response(status_code=500, content=f"Error writing to subprocess: {str(e)}")
 
-    # Read response
+    # Read response with timeout
+    logger.info("Reading response from subprocess with timeout...")
     response = bytearray()
-    logger.info("Reading response...")
-    while True:
-        try:
-            chunk = await proc.stdout.read(1024)
-            if not chunk:
-                logger.info("EOF reached")
+    try:
+        # Set a reasonable timeout (e.g., 30 seconds)
+        import asyncio
+        timeout_seconds = 30
+        start_time = asyncio.get_event_loop().time()
+        
+        while True:
+            elapsed = asyncio.get_event_loop().time() - start_time
+            if elapsed > timeout_seconds:
+                logger.error("Timeout reading response from subprocess after %d seconds", timeout_seconds)
                 break
-            response.extend(chunk)
-            logger.debug("Received chunk: %s", chunk)
-            # Check if we have a complete JSON message
+                
             try:
-                response_str = bytes(response).decode("utf-8")
-                logger.debug("Decoded response: %s", response_str)
-                # More robust JSON-RPC detection
-                # Check if we have a complete JSON object
-                if len(response_str.strip()) > 0:
-                    # Try to parse as JSON
-                    import json
-                    try:
-                        json_data = json.loads(response_str)
-                        # Check if it's a valid JSON-RPC response
-                        if isinstance(json_data, dict) and "jsonrpc" in json_data:
-                            # Check if it's a response (has id or error)
-                            if "id" in json_data or "error" in json_data:
-                                logger.info("Complete JSON-RPC response detected")
-                                break
-                    except json.JSONDecodeError as e:
-                        # If JSON parsing fails, continue reading
-                        logger.debug("JSON parsing failed: %s", str(e))
-                        # Continue reading
+                chunk = await asyncio.wait_for(proc.stdout.read(1024), timeout=5.0)
+                logger.debug("Received chunk of size: %d", len(chunk))
+                
+                if not chunk:
+                    logger.info("EOF reached from subprocess")
+                    break
+                
+                response.extend(chunk)
+                logger.debug("Extended response with chunk, total size: %d", len(response))
+                
+                # Check if we have a complete JSON message
+                try:
+                    response_str = bytes(response).decode("utf-8")
+                    logger.debug("Decoded response: %s", response_str[:200] + "..." if len(response_str) > 200 else response_str)
+                    
+                    # More robust JSON-RPC detection
+                    # Check if we have a complete JSON object
+                    if len(response_str.strip()) > 0:
+                        # Try to parse as JSON
+                        import json
+                        try:
+                            json_data = json.loads(response_str)
+                            # Check if it's a valid JSON-RPC response
+                            if isinstance(json_data, dict) and "jsonrpc" in json_data:
+                                # Check if it's a response (has id or error)
+                                if "id" in json_data or "error" in json_data:
+                                    logger.info("Complete JSON-RPC response detected")
+                                    logger.info("Full response: %s", response_str)
+                                    break
+                                else:
+                                    logger.debug("JSON-RPC response missing id or error field")
+                        except json.JSONDecodeError as e:
+                            # If JSON parsing fails, continue reading
+                            logger.debug("JSON parsing failed (expected during partial reads): %s", str(e))
+                            # Continue reading
+                            continue
+                    else:
+                        # Empty response, continue reading
+                        logger.debug("Empty response, continuing to read")
                         continue
-                else:
-                    # Empty response, continue reading
+                except Exception as e:
+                    logger.warning("Decoding failed: %s", str(e))
+                    # Continue reading
                     continue
-            except Exception as e:
-                logger.warning("Decoding failed: %s", str(e))
-                # Continue reading
+            except asyncio.TimeoutError:
+                logger.warning("Timeout waiting for chunk from subprocess")
+                # Continue reading for more data
                 continue
-        except Exception as e:
-            logger.error("Error reading response: %s", str(e))
-            break
+            except Exception as e:
+                logger.error("Error reading chunk from subprocess: %s", str(e))
+                break
+                
+    except Exception as e:
+        logger.error("Error in response reading loop: %s", str(e))
+        return Response(status_code=500, content=f"Error reading response: {str(e)}")
 
     # Log final response
-    logger.info("Final response: %s", bytes(response).decode())
+    logger.info("Final response size: %d bytes", len(response))
+    if len(response) > 0:
+        try:
+            final_response_str = bytes(response).decode("utf-8")
+            logger.info("Final response preview: %s", final_response_str[:200] + "..." if len(final_response_str) > 200 else final_response_str)
+        except Exception as e:
+            logger.error("Error decoding final response: %s", str(e))
+    else:
+        logger.warning("Final response is empty")
+        
+    logger.info("=== REQUEST PROCESSING COMPLETE ===")
     return Response(content=bytes(response))
 
 @app.on_event("shutdown")
 async def shutdown_event():
+    logger.info("=== SHUTDOWN EVENT ===")
     if proc:
         logger.info("Shutting down subprocess...")
         proc.kill()
         await proc.wait()
         logger.info("Subprocess shut down")
+    logger.info("=== SHUTDOWN COMPLETE ===")