Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[DO NOT MERGE] add some debug logs #4982

Closed
wants to merge 4 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 23 additions & 13 deletions openhands/server/github.py
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
import os
import time

from github import Github
from github.GithubException import GithubException
Expand All @@ -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
Expand All @@ -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):
Expand All @@ -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

Expand All @@ -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')
Expand All @@ -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)
Expand Down
12 changes: 12 additions & 0 deletions openhands/server/listen.py
Original file line number Diff line number Diff line change
Expand Up @@ -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',
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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]

Expand All @@ -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

Expand Down Expand Up @@ -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 = {
Expand Down
Loading