Tweak log levels (#4729)

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

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 \

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

openhands/controller/agent_controller.py

@@ -1,5 +1,6 @@
 import asyncio
 import copy
+import os
 import traceback
 from typing import Callable, ClassVar, Type
 
@@ -259,7 +260,11 @@ class AgentController:
             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)
@@ -282,8 +287,12 @@ class AgentController:
             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},
             )
@@ -497,7 +506,9 @@ class AgentController:
 
         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."""
@@ -663,7 +674,7 @@ class AgentController:
         # 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 +705,7 @@ class AgentController:
                 # 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

openhands/core/logger.py

@@ -177,7 +177,7 @@ class SensitiveDataFilter(logging.Filter):
         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')

openhands/server/github.py

@@ -12,7 +12,7 @@ GITHUB_CLIENT_SECRET = os.getenv('GITHUB_CLIENT_SECRET', '').strip()
 
 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
@@ -25,7 +25,7 @@ class UserVerifier:
         """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):
@@ -46,10 +46,10 @@ class UserVerifier:
         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
 
@@ -61,21 +61,21 @@ class UserVerifier:
         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
 
 
@@ -83,10 +83,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:
     Returns:
         github handle of the user
     """
-    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}',