From f983c46448fa5b0aabae19d757d1b72abbba2a6f Mon Sep 17 00:00:00 2001 From: Engel Nyst Date: Mon, 4 Nov 2024 11:39:04 +0100 Subject: [PATCH 1/5] tweak log levels --- openhands/controller/agent_controller.py | 4 ++-- openhands/server/github.py | 22 +++++++++++----------- 2 files changed, 13 insertions(+), 13 deletions(-) diff --git a/openhands/controller/agent_controller.py b/openhands/controller/agent_controller.py index cde15d78d0b1..96d4e8b314bf 100644 --- a/openhands/controller/agent_controller.py +++ b/openhands/controller/agent_controller.py @@ -241,7 +241,7 @@ async def _handle_observation(self, observation: Observation): observation_to_print.content = truncate_content( observation_to_print.content, self.agent.llm.config.max_message_chars ) - self.log('debug', str(observation_to_print), extra={'msg_type': 'OBSERVATION'}) + self.log('info', str(observation_to_print), extra={'msg_type': 'OBSERVATION'}) # Merge with the metrics from the LLM - it will to synced to the controller's local metrics in update_state_after_step() if observation.llm_metrics is not None: @@ -495,7 +495,7 @@ async def _step(self) -> None: self.event_stream.add_event(action, EventSource.AGENT) await self.update_state_after_step() - self.log('debug', str(action), extra={'msg_type': 'ACTION'}) + self.log('info', str(action), extra={'msg_type': 'ACTION'}) async def _delegate_step(self): """Executes a single step of the delegate agent.""" diff --git a/openhands/server/github.py b/openhands/server/github.py index 774b1697e7ad..4d084a78a049 100644 --- a/openhands/server/github.py +++ b/openhands/server/github.py @@ -11,7 +11,7 @@ class UserVerifier: def __init__(self) -> None: - logger.info('Initializing UserVerifier') + logger.debug('Initializing UserVerifier') self.file_users: list[str] | None = None self.sheets_client: GoogleSheetsClient | None = None self.spreadsheet_id: str | None = None @@ -24,7 +24,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.info('GITHUB_USER_LIST_FILE not configured') + logger.debug('GITHUB_USER_LIST_FILE not configured') return if not os.path.exists(waitlist): @@ -45,10 +45,10 @@ def _init_sheets_client(self) -> None: sheet_id = os.getenv('GITHUB_USERS_SHEET_ID') if not sheet_id: - logger.info('GITHUB_USERS_SHEET_ID not configured') + logger.debug('GITHUB_USERS_SHEET_ID not configured') return - logger.info('Initializing Google Sheets integration') + logger.debug('Initializing Google Sheets integration') self.sheets_client = GoogleSheetsClient() self.spreadsheet_id = sheet_id @@ -60,21 +60,21 @@ def is_user_allowed(self, username: str) -> bool: if not self.is_active(): return True - logger.info(f'Checking if GitHub user {username} is allowed') + logger.debug(f'Checking if GitHub user {username} is allowed') if self.file_users: if username in self.file_users: - logger.info(f'User {username} found in text file allowlist') + logger.debug(f'User {username} found in text file allowlist') return True logger.debug(f'User {username} not found in text file allowlist') if self.sheets_client and self.spreadsheet_id: sheet_users = self.sheets_client.get_usernames(self.spreadsheet_id) if username in sheet_users: - logger.info(f'User {username} found in Google Sheets allowlist') + logger.debug(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 any allowlist') + logger.debug(f'User {username} not found in any allowlist') return False @@ -82,10 +82,10 @@ async def authenticate_github_user(auth_token) -> bool: user_verifier = UserVerifier() if not user_verifier.is_active(): - logger.info('No user verification sources configured - allowing all users') + logger.debug('No user verification sources configured - allowing all users') return True - logger.info('Checking GitHub token') + logger.debug('Checking GitHub token') if not auth_token: logger.warning('No GitHub token provided') @@ -112,7 +112,7 @@ async def get_github_user(token: str) -> str: If successful, error_message is None If failed, login is None and error_message contains the error """ - logger.info('Fetching GitHub user info from token') + logger.debug('Fetching GitHub user info from token') headers = { 'Accept': 'application/vnd.github+json', 'Authorization': f'Bearer {token}', From 9d066045faa0acda3ba81443c29007400fe64c2c Mon Sep 17 00:00:00 2001 From: Engel Nyst Date: Sun, 10 Nov 2024 11:16:49 +0100 Subject: [PATCH 2/5] revert info --- openhands/controller/agent_controller.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/openhands/controller/agent_controller.py b/openhands/controller/agent_controller.py index 089c9c6b091d..2ee30e130ca3 100644 --- a/openhands/controller/agent_controller.py +++ b/openhands/controller/agent_controller.py @@ -259,7 +259,7 @@ async def _handle_observation(self, observation: Observation): observation_to_print.content = truncate_content( observation_to_print.content, self.agent.llm.config.max_message_chars ) - self.log('info', str(observation_to_print), extra={'msg_type': 'OBSERVATION'}) + self.log('debug', str(observation_to_print), extra={'msg_type': 'OBSERVATION'}) if observation.llm_metrics is not None: self.agent.llm.metrics.merge(observation.llm_metrics) From acb22b2212de5725e2de8f1b02b9791d7c8f72a3 Mon Sep 17 00:00:00 2001 From: Engel Nyst Date: Sun, 10 Nov 2024 11:37:09 +0100 Subject: [PATCH 3/5] override log level for debug to info --- README.md | 1 + docs/modules/usage/how-to/headless-mode.md | 1 + docs/modules/usage/installation.mdx | 1 + openhands/controller/agent_controller.py | 9 +++++++-- openhands/core/logger.py | 4 ++-- 5 files changed, 12 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index da882d79bc0d..23b7c57d5a9e 100644 --- a/README.md +++ b/README.md @@ -44,6 +44,7 @@ docker run -it --pull=always \ -e SANDBOX_RUNTIME_CONTAINER_IMAGE=docker.all-hands.dev/all-hands-ai/runtime:0.13-nikolaik \ -v /var/run/docker.sock:/var/run/docker.sock \ -p 3000:3000 \ + -e LOG_ALL_EVENTS=true \ --add-host host.docker.internal:host-gateway \ --name openhands-app \ docker.all-hands.dev/all-hands-ai/openhands:0.13 diff --git a/docs/modules/usage/how-to/headless-mode.md b/docs/modules/usage/how-to/headless-mode.md index d3fc1c2947c7..adba43e47468 100644 --- a/docs/modules/usage/how-to/headless-mode.md +++ b/docs/modules/usage/how-to/headless-mode.md @@ -49,6 +49,7 @@ docker run -it \ -e WORKSPACE_MOUNT_PATH=$WORKSPACE_BASE \ -e LLM_API_KEY=$LLM_API_KEY \ -e LLM_MODEL=$LLM_MODEL \ + -e LOG_ALL_EVENTS=true \ -v $WORKSPACE_BASE:/opt/workspace_base \ -v /var/run/docker.sock:/var/run/docker.sock \ --add-host host.docker.internal:host-gateway \ diff --git a/docs/modules/usage/installation.mdx b/docs/modules/usage/installation.mdx index c01c3f98997b..7a7f2c352b6d 100644 --- a/docs/modules/usage/installation.mdx +++ b/docs/modules/usage/installation.mdx @@ -17,6 +17,7 @@ docker run -it --rm --pull=always \ -e SANDBOX_RUNTIME_CONTAINER_IMAGE=docker.all-hands.dev/all-hands-ai/runtime:0.13-nikolaik \ -v /var/run/docker.sock:/var/run/docker.sock \ -p 3000:3000 \ + -e LOG_ALL_EVENTS=true \ --add-host host.docker.internal:host-gateway \ --name openhands-app \ docker.all-hands.dev/all-hands-ai/openhands:0.13 diff --git a/openhands/controller/agent_controller.py b/openhands/controller/agent_controller.py index 2ee30e130ca3..16881fb81dd2 100644 --- a/openhands/controller/agent_controller.py +++ b/openhands/controller/agent_controller.py @@ -1,5 +1,6 @@ import asyncio import copy +import os import traceback from typing import Callable, ClassVar, Type @@ -164,6 +165,10 @@ def log(self, level: str, message: str, extra: dict | None = None): Args: message (str): The message to log. """ + # override log level to 'info' if LOG_ALL_EVENTS is set and level is 'debug' + if os.getenv('LOG_ALL_EVENTS') in ('true', '1') and level.lower() == 'debug': + level = 'info' + message = f'[Agent Controller {self.id}] {message}' getattr(logger, level)(message, extra=extra, stacklevel=2) @@ -663,7 +668,7 @@ def _init_history(self): # sanity check if start_id > end_id + 1: self.log( - 'debug', + 'warning', f'start_id {start_id} is greater than end_id + 1 ({end_id + 1}). History will be empty.', ) self.state.history = [] @@ -694,7 +699,7 @@ def _init_history(self): # Match with most recent unmatched delegate action if not delegate_action_ids: self.log( - 'error', + 'warning', f'Found AgentDelegateObservation without matching action at id={event.id}', ) continue diff --git a/openhands/core/logger.py b/openhands/core/logger.py index f6a84669f633..20a4a4d6581a 100644 --- a/openhands/core/logger.py +++ b/openhands/core/logger.py @@ -177,7 +177,7 @@ def filter(self, record): return True -def get_console_handler(log_level=logging.INFO, extra_info: str | None = None): +def get_console_handler(log_level: int = logging.INFO, extra_info: str | None = None): """Returns a console handler for logging.""" console_handler = logging.StreamHandler() console_handler.setLevel(log_level) @@ -188,7 +188,7 @@ def get_console_handler(log_level=logging.INFO, extra_info: str | None = None): return console_handler -def get_file_handler(log_dir, log_level=logging.INFO): +def get_file_handler(log_dir: str, log_level: int = logging.INFO): """Returns a file handler for logging.""" os.makedirs(log_dir, exist_ok=True) timestamp = datetime.now().strftime('%Y-%m-%d') From b91e54c262cdd2e6c1ed262faae969609d178270 Mon Sep 17 00:00:00 2001 From: Engel Nyst Date: Mon, 11 Nov 2024 23:14:14 +0100 Subject: [PATCH 4/5] do tricks on spot --- openhands/controller/agent_controller.py | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/openhands/controller/agent_controller.py b/openhands/controller/agent_controller.py index 16881fb81dd2..dabc8f4d9004 100644 --- a/openhands/controller/agent_controller.py +++ b/openhands/controller/agent_controller.py @@ -165,10 +165,6 @@ def log(self, level: str, message: str, extra: dict | None = None): Args: message (str): The message to log. """ - # override log level to 'info' if LOG_ALL_EVENTS is set and level is 'debug' - if os.getenv('LOG_ALL_EVENTS') in ('true', '1') and level.lower() == 'debug': - level = 'info' - message = f'[Agent Controller {self.id}] {message}' getattr(logger, level)(message, extra=extra, stacklevel=2) @@ -264,7 +260,11 @@ async def _handle_observation(self, observation: Observation): observation_to_print.content = truncate_content( observation_to_print.content, self.agent.llm.config.max_message_chars ) - self.log('debug', str(observation_to_print), extra={'msg_type': 'OBSERVATION'}) + # Use info level if LOG_ALL_EVENTS is set + log_level = 'info' if os.getenv('LOG_ALL_EVENTS') in ('true', '1') else 'debug' + self.log( + log_level, str(observation_to_print), extra={'msg_type': 'OBSERVATION'} + ) if observation.llm_metrics is not None: self.agent.llm.metrics.merge(observation.llm_metrics) @@ -502,7 +502,9 @@ async def _step(self) -> None: await self.update_state_after_step() - self.log('debug', str(action), extra={'msg_type': 'ACTION'}) + # Use info level if LOG_ALL_EVENTS is set + log_level = 'info' if os.getenv('LOG_ALL_EVENTS') in ('true', '1') else 'debug' + self.log(log_level, str(action), extra={'msg_type': 'ACTION'}) async def _delegate_step(self): """Executes a single step of the delegate agent.""" From 1aa983c475077dd68048b0da8027936c714eb7f8 Mon Sep 17 00:00:00 2001 From: Engel Nyst Date: Mon, 11 Nov 2024 23:22:15 +0100 Subject: [PATCH 5/5] messageaction too --- openhands/controller/agent_controller.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/openhands/controller/agent_controller.py b/openhands/controller/agent_controller.py index dabc8f4d9004..d0b806a3f19b 100644 --- a/openhands/controller/agent_controller.py +++ b/openhands/controller/agent_controller.py @@ -287,8 +287,12 @@ async def _handle_message_action(self, action: MessageAction): action (MessageAction): The message action to handle. """ if action.source == EventSource.USER: + # Use info level if LOG_ALL_EVENTS is set + log_level = ( + 'info' if os.getenv('LOG_ALL_EVENTS') in ('true', '1') else 'debug' + ) self.log( - 'debug', + log_level, str(action), extra={'msg_type': 'ACTION', 'event_source': EventSource.USER}, )