diff --git a/openhands/server/github.py b/openhands/server/github.py index 5e26beaa9d2b..1001f7f7b030 100644 --- a/openhands/server/github.py +++ b/openhands/server/github.py @@ -1,4 +1,5 @@ import os +import time from github import Github from github.GithubException import GithubException @@ -14,7 +15,7 @@ class UserVerifier: def __init__(self) -> None: - logger.debug('Initializing UserVerifier') + logger.info('Initializing UserVerifier') self.file_users: list[str] | None = None self.sheets_client: GoogleSheetsClient | None = None self.spreadsheet_id: str | None = None @@ -27,7 +28,7 @@ def _init_file_users(self) -> None: """Load users from text file if configured""" waitlist = os.getenv('GITHUB_USER_LIST_FILE') if not waitlist: - logger.debug('GITHUB_USER_LIST_FILE not configured') + logger.info('GITHUB_USER_LIST_FILE not configured') return if not os.path.exists(waitlist): @@ -48,10 +49,10 @@ def _init_sheets_client(self) -> None: sheet_id = os.getenv('GITHUB_USERS_SHEET_ID') if not sheet_id: - logger.debug('GITHUB_USERS_SHEET_ID not configured') + logger.info('GITHUB_USERS_SHEET_ID not configured') return - logger.debug('Initializing Google Sheets integration') + logger.info('Initializing Google Sheets integration') self.sheets_client = GoogleSheetsClient() self.spreadsheet_id = sheet_id @@ -60,41 +61,50 @@ def is_active(self) -> bool: def is_user_allowed(self, username: str) -> bool: """Check if user is allowed based on file and/or sheet configuration""" + start_time = time.time() if not self.is_active(): return True - logger.debug(f'Checking if GitHub user {username} is allowed') + logger.info(f'Checking if GitHub user {username} is allowed') if self.file_users: if username in self.file_users: - logger.debug(f'User {username} found in text file allowlist') + logger.info(f'User {username} found in text file allowlist') return True - logger.debug(f'User {username} not found in text file allowlist') + logger.info(f'User {username} not found in text file allowlist') + + logger.info(f'Took {time.time() - start_time:.2f} seconds to check file users') if self.sheets_client and self.spreadsheet_id: sheet_users = self.sheets_client.get_usernames(self.spreadsheet_id) if username in sheet_users: - logger.debug(f'User {username} found in Google Sheets allowlist') + logger.info(f'User {username} found in Google Sheets allowlist') return True - logger.debug(f'User {username} not found in Google Sheets allowlist') + logger.info(f'User {username} not found in Google Sheets allowlist') + + logger.info(f'Took {time.time() - start_time:.2f} seconds to check sheet users') - logger.debug(f'User {username} not found in any allowlist') + logger.info(f'User {username} not found in any allowlist') return False async def authenticate_github_user(auth_token) -> bool: user_verifier = UserVerifier() + logger.info('Initialized user verifier') if not user_verifier.is_active(): - logger.debug('No user verification sources configured - allowing all users') + logger.info('No user verification sources configured - allowing all users') return True - logger.debug('Checking GitHub token') + logger.info('Checking GitHub token') if not auth_token: logger.warning('No GitHub token provided') return False + start_time = time.time() + logger.info('Getting GitHub user from token') login = await get_github_user(auth_token) + logger.info(f'Took {time.time() - start_time:.2f} seconds to get GitHub user') if not user_verifier.is_user_allowed(login): logger.warning(f'GitHub user {login} not in allow list') @@ -114,7 +124,7 @@ async def get_github_user(token: str) -> str: Returns: github handle of the user """ - logger.debug('Fetching GitHub user info from token') + logger.info('Fetching GitHub user info from token') try: g = Github(token) user = await call_sync_from_async(g.get_user) diff --git a/openhands/server/listen.py b/openhands/server/listen.py index d18bea277404..ffbd460200ce 100644 --- a/openhands/server/listen.py +++ b/openhands/server/listen.py @@ -183,6 +183,8 @@ async def attach_session(request: Request, call_next): Returns: Response: The response from the next middleware or route handler. """ + logger.info(f'Attaching session for {request.url.path}') + start_time = time.time() non_authed_paths = [ '/api/options/', '/api/github/callback', @@ -238,6 +240,8 @@ async def attach_session(request: Request, call_next): request.state.conversation = await session_manager.attach_to_conversation( request.state.sid ) + end_time = time.time() + logger.info(f'Attach session time: {end_time - start_time:.2f}s') if request.state.conversation is None: return JSONResponse( status_code=status.HTTP_404_NOT_FOUND, @@ -486,9 +490,12 @@ async def list_files(request: Request, path: str | None = None): status_code=status.HTTP_404_NOT_FOUND, content={'error': 'Runtime not yet initialized'}, ) + start_time = time.time() runtime: Runtime = request.state.conversation.runtime file_list = await call_sync_from_async(runtime.list_files, path) + end_time = time.time() + logger.info(f'List files time: {end_time - start_time:.2f}s') if path: file_list = [os.path.join(path, f) for f in file_list] @@ -509,6 +516,8 @@ async def filter_for_gitignore(file_list, base_path): return file_list file_list = await filter_for_gitignore(file_list, '') + end_time = time.time() + logger.info(f'Filter files time: {end_time - start_time:.2f}s') return file_list @@ -862,12 +871,15 @@ def github_callback(auth_code: AuthCode): @app.post('/api/authenticate') async def authenticate(request: Request): + logger.info('Authenticating user via GitHub waitlist') token = request.headers.get('X-GitHub-Token') if not await authenticate_github_user(token): + logger.warning('User not authorized via GitHub waitlist') return JSONResponse( status_code=status.HTTP_401_UNAUTHORIZED, content={'error': 'Not authorized via GitHub waitlist'}, ) + logger.info('User authenticated via GitHub waitlist') # Create a signed JWT token with 1-hour expiration cookie_data = {