Update app.py

app.py

@@ -1,6 +1,8 @@
 import asyncio
 import os
 import logging
+import requests
+import json
 from fastapi import FastAPI, Request, Response
 
 # Set up logging with more detailed configuration
@@ -18,16 +20,17 @@ 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")
     logger.info("Attempting to start subprocess...")
     logger.info("Token environment variable exists: %s", token is not None)
+    
     if not token:
         logger.error("GITHUB_PERSONAL_ACCESS_TOKEN environment variable not set")
         return
 
     logger.info("Starting subprocess with token: %s", token[:10] + "...")
     try:
+        # Create the subprocess to run the github-mcp-server
         proc = await asyncio.create_subprocess_exec(
             '/usr/local/bin/github-mcp-server', 'stdio',
             stdin=asyncio.subprocess.PIPE,
@@ -36,26 +39,29 @@ async def startup_event():
             env={"GITHUB_PERSONAL_ACCESS_TOKEN": token}
         )
         logger.info("Subprocess created successfully with PID: %s", proc.pid)
-        # Test if subprocess is actually running
+        
+        # Check if subprocess is actually running
         if proc.returncode is None:
             logger.info("Subprocess appears to be running")
         else:
             logger.warning("Subprocess may have exited immediately with code: %s", proc.returncode)
+            
+        # Start the background task to log stderr
         asyncio.create_task(log_stderr())
         logger.info("=== STARTUP COMPLETE ===")
     except Exception as e:
         logger.error("Failed to create subprocess: %s", str(e))
+        # Re-raise to crash the application startup, as the proxy cannot function without the subprocess
         raise
 
 async def log_stderr():
+    """Reads and logs output from the subprocess's stderr stream."""
     if proc and proc.stderr:
         logger.info("Starting stderr logging task")
-        while 
-
-<< 35 Characters hidden >>
-
-   try:
+        while not proc.stderr.at_eof():
+            try:
                 line = await proc.stderr.readline()
+
                 if line:
                     logger.debug("github-mcp-server stderr: %s", line.decode().strip())
                 else:
@@ -70,50 +76,50 @@ async def proxy(request: Request):
     logger.info("Request method: %s", request.method)
     logger.info("Request headers: %s", dict(request.headers))
     
+    # 1. Check subprocess health
     if not proc or not proc.stdin or not proc.stdout:
         logger.error("Subprocess not running - returning 500")
         return Response(status_code=500, content="Subprocess not running")
 
-    # Log incoming request
+    # 2. Log incoming request body
     body = await request.body()
-    logger.info("Received request body: %s", body.decode())
+    # Decode only a small portion for logging to prevent console spam for huge payloads
+    logger.info("Received request body preview: %s", body.decode()[:200] + "..." if len(body) > 200 else body.decode())
     
-    # Token verification for debugging
-    import requests
+    # 3. Token verification for debugging (Synchronous call to external API)
     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:
+            # Note: requests.get is blocking, but typically fast enough here.
+            response_gh = requests.get("https://api.github.com/user", headers={"Authorization": f"token {token}"}, timeout=5)
+            logger.info("Token verification response status: %s", response_gh.status_code)
+            if response_gh.status_code == 200:
                 logger.info("GitHub token verification successful")
             else:
-                logger.error("GitHub token verification failed with status code: %s", response.status_code)
+                logger.error("GitHub token verification failed with status code: %s", response_gh.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
+    # 4. Send request to subprocess
     logger.info("Sending request to subprocess...")
     try:
         proc.stdin.write(body)
         await proc.stdin.drain()
-        logger.info("Successfully wrote to subprocess stdin")
+        logger.info("Successfully wrote request body 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 with timeout
+    # 5. Read response with timeout and robust JSON detection
     logger.info("Reading response from subprocess with timeout...")
     response = bytearray()
+    timeout_seconds = 30
+    start_time = asyncio.get_event_loop().time()
+    
     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:
@@ -121,6 +127,7 @@ async def proxy(request: Request):
                 break
                 
             try:
+                # Use wait_for to enforce a per-read timeout
                 chunk = await asyncio.wait_for(proc.stdout.read(1024), timeout=5.0)
                 logger.debug("Received chunk of size: %d", len(chunk))
                 
@@ -131,63 +138,53 @@ async def proxy(request: Request):
                 response.extend(chunk)
                 logger.debug("Extended response with chunk, total size: %d", len(response))
                 
-                # Check if we have a complete JSON message
+                # Check for complete JSON-RPC 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
+                        # Attempt to parse as JSON
                         try:
                             json_data = json.loads(response_str)
-                            # Check if it's a valid JSON-RPC response
+                            
+                            # Check for mandatory JSON-RPC fields in a 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)
+                                    # Log only a preview of the full response
+                                    logger.info("Full response preview: %s", response_str[:200] + "..." if len(response_str) > 200 else response_str)
                                     break
+                                # If it's a request, we keep reading (though the subprocess should only send responses)
                                 else:
-                                    logger.debug("JSON-RPC response missing id or error field")
+                                    logger.debug("JSON-RPC object found, but not a final response (missing 'id' or 'error'). Continuing to read.")
+                            
                         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
+                            # Expected when reading partial JSON data. Continue reading.
+                            logger.debug("JSON parsing failed (partial read): %s", str(e))
                             continue
                     else:
-                        # Empty response, continue reading
                         logger.debug("Empty response, continuing to read")
                         continue
-                except Exception as e:
-                    logger.warning("Decoding failed: %s", str(e))
-                    # Continue reading
+                except UnicodeDecodeError as e:
+                    logger.warning("Decoding failed (partial multi-byte char): %s", str(e))
                     continue
             except asyncio.TimeoutError:
-                logger.warning("Timeout waiting for chunk from subprocess")
-                # Continue reading for more data
+                logger.warning("Timeout waiting for chunk from subprocess, continuing loop.")
+                # This timeout is okay, it allows the main timeout check to fire if needed.
                 continue
             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))
+        logger.error("Error in primary response reading loop: %s", str(e))
         return Response(status_code=500, content=f"Error reading response: {str(e)}")
 
-    # Log final response
+    # 6. Final response check and return
     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")
-        
+    if len(response) == 0:
+        logger.error("Final response is empty after reading loop.")
+
     logger.info("=== REQUEST PROCESSING COMPLETE ===")
     return Response(content=bytes(response))