Merge branch 'main' of github.com:All-Hands-AI/OpenHands into enyst/loggers

This reverts commit 6e139ffa74.

agenthub/browsing_agent/browsing_agent.py

@@ -197,7 +197,7 @@ class BrowsingAgent(Agent):
                 )
             except Exception as e:
                 logger.error(
-                    'Error when trying to process the accessibility tree: %s', e
+                    f'Error when trying to process the accessibility tree: {e}'
                 )
                 return MessageAction('Error encountered when browsing.')
 

evaluation/utils/shared.py

@@ -40,7 +40,6 @@ class EvalMetadata(BaseModel):
     def model_dump_json(self, *args, **kwargs):
         dumped = super().model_dump_json(*args, **kwargs)
         dumped_dict = json.loads(dumped)
-        logger.debug(f'Dumped metadata: {dumped_dict}')
         # avoid leaking sensitive information
         dumped_dict['llm_config'] = self.llm_config.to_safe_dict()
         return json.dumps(dumped_dict)

openhands/controller/agent_controller.py

@@ -358,7 +358,7 @@ class AgentController:
             # global metrics should be shared between parent and child
             metrics=self.state.metrics,
         )
-        logger.info(
+        logger.debug(
             f'[Agent Controller {self.id}]: start delegate, creating agent {delegate_agent.name} using LLM {llm}'
         )
         self.delegate = AgentController(
@@ -387,16 +387,15 @@ class AgentController:
 
         if self.delegate is not None:
             assert self.delegate != self
-            if self.delegate.get_agent_state() == AgentState.PAUSED:
-                await asyncio.sleep(1)
-            else:
-                await self._delegate_step()
             return
 
-        logger.info(
-            f'{self.agent.name} LEVEL {self.state.delegate_level} LOCAL STEP {self.state.local_iteration} GLOBAL STEP {self.state.iteration}',
-            extra={'msg_type': 'STEP'},
-        )
+        if self.state.delegate_level == 0:
+            logger.info(f'{self.agent.name} STEP {self.state.iteration}')
+        else:
+            logger.info(
+                f'{self.agent.name} LEVEL {self.state.delegate_level} LOCAL STEP {self.state.local_iteration} GLOBAL STEP {self.state.iteration}',
+                extra={'msg_type': 'STEP'},
+            )
 
         # check if agent hit the resources limit
         stop_step = False
@@ -450,12 +449,13 @@ class AgentController:
 
     async def _delegate_step(self):
         """Executes a single step of the delegate agent."""
-        logger.debug(f'[Agent Controller {self.id}] Delegate not none, awaiting...')
         await self.delegate._step()  # type: ignore[union-attr]
-        logger.debug(f'[Agent Controller {self.id}] Delegate step done')
+
+        # when the delegate step is done, check its state
         assert self.delegate is not None
         delegate_state = self.delegate.get_agent_state()
-        logger.debug(f'[Agent Controller {self.id}] Delegate state: {delegate_state}')
+
+        # clean up if the delegate has finished, normally or abnormally
         if delegate_state == AgentState.ERROR:
             # update iteration that shall be shared across agents
             self.state.iteration = self.delegate.state.iteration
@@ -467,7 +467,7 @@ class AgentController:
 
             await self.report_error('Delegator agent encountered an error')
         elif delegate_state in (AgentState.FINISHED, AgentState.REJECTED):
-            logger.info(
+            logger.debug(
                 f'[Agent Controller {self.id}] Delegate agent has finished execution'
             )
             # retrieve delegate result
@@ -509,7 +509,9 @@ class AgentController:
         """
         stop_step = False
         if self.state.traffic_control_state == TrafficControlState.PAUSED:
-            logger.info('Hitting traffic control, temporarily resume upon user request')
+            logger.debug(
+                'Hitting traffic control, temporarily resume upon user request'
+            )
             self.state.traffic_control_state = TrafficControlState.NORMAL
         else:
             self.state.traffic_control_state = TrafficControlState.THROTTLING

openhands/controller/state/task.py

@@ -108,7 +108,7 @@ class Task:
             TaskInvalidStateError: If the provided state is invalid.
         """
         if state not in STATES:
-            logger.error('Invalid state: %s', state)
+            logger.error(f'Invalid state: {state}')
             raise TaskInvalidStateError(state)
         self.state = state
         if (

openhands/core/logger.py

@@ -1,13 +1,22 @@
+import copy
+import glob
 import logging
 import os
 import re
 import sys
 import traceback
 from datetime import datetime
+from enum import Enum
 from typing import Literal, Mapping
 
 from termcolor import colored
 
+
+class LlmLogType(Enum):
+    PROMPT = 'prompt'
+    RESPONSE = 'response'
+
+
 LOG_LEVEL = os.getenv('LOG_LEVEL', 'INFO').upper()
 DEBUG = os.getenv('DEBUG', 'False').lower() in ['true', '1', 'yes']
 if DEBUG:
@@ -35,6 +44,7 @@ ColorType = Literal[
 ]
 
 LOG_COLORS: Mapping[str, ColorType] = {
+    'DEBUG': 'blue',
     'ACTION': 'green',
     'USER_ACTION': 'light_red',
     'OBSERVATION': 'yellow',
@@ -46,8 +56,10 @@ LOG_COLORS: Mapping[str, ColorType] = {
 
 
 class ColoredFormatter(logging.Formatter):
-    def format(self, record):
-        msg_type = record.__dict__.get('msg_type')
+    """Formatter for colored logging in console."""
+
+    def format(self, record: logging.LogRecord) -> str:
+        msg_type = record.__dict__.get('msg_type', 'INFO')
         event_source = record.__dict__.get('event_source')
         if event_source:
             new_msg_type = f'{event_source.upper()}_{msg_type}'
@@ -70,21 +82,45 @@ class ColoredFormatter(logging.Formatter):
         return super().format(record)
 
 
-console_formatter = ColoredFormatter(
+class NoColorFormatter(logging.Formatter):
+    """Formatter for non-colored logging in files."""
+
+    def format(self, record: logging.LogRecord) -> str:
+        # Create a deep copy of the record to avoid modifying the original
+        new_record: logging.LogRecord = copy.deepcopy(record)
+        # Strip ANSI color codes from the message
+        new_record.msg = strip_ansi(new_record.msg)
+
+        return super().format(new_record)
+
+
+def strip_ansi(s: str) -> str:
+    """
+    Removes ANSI escape sequences from str, as defined by ECMA-048 in
+    http://www.ecma-international.org/publications/files/ECMA-ST/Ecma-048.pdf
+    # https://github.com/ewen-lbh/python-strip-ansi/blob/master/strip_ansi/__init__.py
+    """
+    pattern = re.compile(r'\x1B\[\d+(;\d+){0,2}m')
+    stripped = pattern.sub('', s)
+    return stripped
+
+
+console_formatter: ColoredFormatter = ColoredFormatter(
     '\033[92m%(asctime)s - %(name)s:%(levelname)s\033[0m: %(filename)s:%(lineno)s - %(message)s',
     datefmt='%H:%M:%S',
 )
 
-file_formatter = logging.Formatter(
+file_formatter: NoColorFormatter = NoColorFormatter(
     '%(asctime)s - %(name)s:%(levelname)s: %(filename)s:%(lineno)s - %(message)s',
     datefmt='%H:%M:%S',
 )
-llm_formatter = logging.Formatter('%(message)s')
+
+llm_formatter: logging.Formatter = logging.Formatter('%(message)s')
 
 
 class SensitiveDataFilter(logging.Filter):
-    def filter(self, record):
-        # start with attributes
+    def filter(self, record: logging.LogRecord) -> bool:
+        # Start with attributes
         sensitive_patterns = [
             'api_key',
             'aws_access_key_id',
@@ -94,17 +130,21 @@ class SensitiveDataFilter(logging.Filter):
             'jwt_secret',
         ]
 
-        # add env var names
+        # Add env var names
         env_vars = [attr.upper() for attr in sensitive_patterns]
         sensitive_patterns.extend(env_vars)
 
-        # and some special cases
-        sensitive_patterns.append('JWT_SECRET')
-        sensitive_patterns.append('LLM_API_KEY')
-        sensitive_patterns.append('GITHUB_TOKEN')
-        sensitive_patterns.append('SANDBOX_ENV_GITHUB_TOKEN')
+        # And some special cases
+        sensitive_patterns.extend(
+            [
+                'JWT_SECRET',
+                'LLM_API_KEY',
+                'GITHUB_TOKEN',
+                'SANDBOX_ENV_GITHUB_TOKEN',
+            ]
+        )
 
-        # this also formats the message with % args
+        # This also formats the message with % args
         msg = record.getMessage()
         record.args = ()
 
@@ -112,25 +152,29 @@ class SensitiveDataFilter(logging.Filter):
             pattern = rf"{attr}='?([\w-]+)'?"
             msg = re.sub(pattern, f"{attr}='******'", msg)
 
-        # passed with msg
+        # Passed with msg
         record.msg = msg
         return True
 
 
-def get_console_handler(log_level=logging.INFO):
+def get_console_handler(log_level: int = logging.INFO) -> logging.StreamHandler:
     """Returns a console handler for logging."""
-    console_handler = logging.StreamHandler()
+    console_handler: logging.StreamHandler = logging.StreamHandler()
     console_handler.setLevel(log_level)
     console_handler.setFormatter(console_formatter)
     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
+) -> logging.FileHandler:
     """Returns a file handler for logging."""
     os.makedirs(log_dir, exist_ok=True)
-    timestamp = datetime.now().strftime('%Y-%m-%d')
-    file_name = f'openhands_{timestamp}.log'
-    file_handler = logging.FileHandler(os.path.join(log_dir, file_name))
+    timestamp: str = datetime.now().strftime('%Y-%m-%d')
+    file_name: str = f'openhands_{timestamp}.log'
+    file_handler: logging.FileHandler = logging.FileHandler(
+        os.path.join(log_dir, file_name)
+    )
     file_handler.setLevel(log_level)
     file_handler.setFormatter(file_formatter)
     return file_handler
@@ -165,14 +209,14 @@ openhands_logger.setLevel(current_log_level)
 
 if current_log_level == logging.DEBUG:
     LOG_TO_FILE = True
-    openhands_logger.info('DEBUG mode enabled.')
 
 openhands_logger.addHandler(get_console_handler(current_log_level))
 openhands_logger.addFilter(SensitiveDataFilter(openhands_logger.name))
 openhands_logger.propagate = False
 openhands_logger.debug('Logging initialized')
 
-LOG_DIR = os.path.join(
+# Define LOG_DIR after setting up the logger
+LOG_DIR: str = os.path.join(
     # parent dir of openhands/core (i.e., root of the repo)
     os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__)))),
     'logs',
@@ -191,71 +235,101 @@ logging.getLogger('LiteLLM Proxy').disabled = True
 
 
 class LlmFileHandler(logging.FileHandler):
-    """# LLM prompt and response logging"""
+    """LLM prompt and response logging"""
 
-    def __init__(self, filename, mode='a', encoding='utf-8', delay=False):
-        """Initializes an instance of LlmFileHandler.
+    _prompt_instances: dict[str, 'LlmFileHandler'] = {}
+    _response_instances: dict[str, 'LlmFileHandler'] = {}
 
-        Args:
-            filename (str): The name of the log file.
-            mode (str, optional): The file mode. Defaults to 'a'.
-            encoding (str, optional): The file encoding. Defaults to None.
-            delay (bool, optional): Whether to delay file opening. Defaults to False.
-        """
-        self.filename = filename
-        self.message_counter = 1
-        if DEBUG:
-            self.session = datetime.now().strftime('%y-%m-%d_%H-%M')
+    @classmethod
+    def get_instance(cls, sid: str, llm_log_type: LlmLogType) -> 'LlmFileHandler':
+        """Get or create an LlmFileHandler instance for the given session ID and filename."""
+        if llm_log_type == LlmLogType.PROMPT:
+            if sid not in cls._prompt_instances:
+                cls._prompt_instances[sid] = cls(sid, llm_log_type.value)
+            return cls._prompt_instances[sid]
+        elif llm_log_type == LlmLogType.RESPONSE:
+            if sid not in cls._response_instances:
+                cls._response_instances[sid] = cls(sid, llm_log_type.value)
+            return cls._response_instances[sid]
         else:
-            self.session = 'default'
-        self.log_directory = os.path.join(LOG_DIR, 'llm', self.session)
+            raise ValueError(
+                f'Invalid llm_log_type: {llm_log_type}. Must be a LlmLogType enum.'
+            )
+
+    def __init__(
+        self,
+        sid: str,
+        filename: str,
+        mode: str = 'a',
+        encoding: str = 'utf-8',
+        delay: bool = True,
+    ) -> None:
+        """Initializes an instance of LlmFileHandler."""
+        self.filename: str = filename
+        self.message_counter: int = 1
+        self.log_directory: str = os.path.join(LOG_DIR, 'llm', sid)
         os.makedirs(self.log_directory, exist_ok=True)
+
         if not DEBUG:
             # Clear the log directory if not in debug mode
             for file in os.listdir(self.log_directory):
-                file_path = os.path.join(self.log_directory, file)
+                file_path: str = os.path.join(self.log_directory, file)
                 try:
                     os.unlink(file_path)
                 except Exception as e:
-                    openhands_logger.error(
-                        'Failed to delete %s. Reason: %s', file_path, e
-                    )
-        filename = f'{self.filename}_{self.message_counter:03}.log'
-        self.baseFilename = os.path.join(self.log_directory, filename)
+                    openhands_logger.error(f'Failed to delete {file_path}. Reason: {e}')
+        else:
+            # In DEBUG mode, continue writing existing log directory
+            # Find the highest message counter
+            existing_files: list[str] = glob.glob(
+                os.path.join(self.log_directory, f'{self.filename}_*.log')
+            )
+            if existing_files:
+                highest_counter: int = max(
+                    int(f.split('_')[-1].split('.')[0]) for f in existing_files
+                )
+                self.message_counter = highest_counter + 1
+
+        filename_full: str = f'{self.filename}_{self.message_counter:03}.log'
+        self.baseFilename: str = os.path.join(self.log_directory, filename_full)
         super().__init__(self.baseFilename, mode, encoding, delay)
 
-    def emit(self, record):
-        """Emits a log record.
+    def emit(self, record: logging.LogRecord) -> None:
+        """Emits a log record."""
 
-        Args:
-            record (logging.LogRecord): The log record to emit.
-        """
-        filename = f'{self.filename}_{self.message_counter:03}.log'
-        self.baseFilename = os.path.join(self.log_directory, filename)
+        filename_full: str = f'{self.filename}_{self.message_counter:03}.log'
+        self.baseFilename = os.path.join(self.log_directory, filename_full)
         self.stream = self._open()
         super().emit(record)
         self.stream.close()
-        openhands_logger.debug('Logging to %s', self.baseFilename)
+        openhands_logger.debug(f'Logging to {self.baseFilename}')
         self.message_counter += 1
 
 
-def _get_llm_file_handler(name: str, log_level: int):
-    # The 'delay' parameter, when set to True, postpones the opening of the log file
-    # until the first log message is emitted.
-    llm_file_handler = LlmFileHandler(name, delay=True)
+def _get_llm_file_handler(
+    llm_log_type: LlmLogType, sid: str, log_level: int
+) -> logging.FileHandler:
+    llm_file_handler: LlmFileHandler = LlmFileHandler.get_instance(sid, llm_log_type)
     llm_file_handler.setFormatter(llm_formatter)
     llm_file_handler.setLevel(log_level)
     return llm_file_handler
 
 
-def _setup_llm_logger(name: str, log_level: int):
-    logger = logging.getLogger(name)
+def _setup_llm_logger(
+    llm_log_type: LlmLogType, sid: str, log_level: int
+) -> logging.Logger:
+    logger: logging.Logger = logging.getLogger(f'{llm_log_type.value}_{sid}')
     logger.propagate = False
     logger.setLevel(log_level)
     if LOG_TO_FILE:
-        logger.addHandler(_get_llm_file_handler(name, log_level))
+        logger.addHandler(_get_llm_file_handler(llm_log_type, sid, log_level))
     return logger
 
 
-llm_prompt_logger = _setup_llm_logger('prompt', current_log_level)
-llm_response_logger = _setup_llm_logger('response', current_log_level)
+def get_llm_loggers(sid: str = 'default') -> dict[LlmLogType, logging.Logger]:
+    return {
+        LlmLogType.PROMPT: _setup_llm_logger(LlmLogType.PROMPT, sid, current_log_level),
+        LlmLogType.RESPONSE: _setup_llm_logger(
+            LlmLogType.RESPONSE, sid, current_log_level
+        ),
+    }

openhands/core/main.py

@@ -125,12 +125,12 @@ async def run_controller(
     initial_state = None
     if config.enable_cli_session:
         try:
-            logger.info(f'Restoring agent state from cli session {event_stream.sid}')
             initial_state = State.restore_from_session(
                 event_stream.sid, event_stream.file_store
             )
+            logger.debug(f'Restored agent state from cli session {event_stream.sid}')
         except Exception as e:
-            logger.info(f'Error restoring state: {e}')
+            logger.debug(f'Cannot restore state: {e}')
 
     # init controller with this initial state
     controller = AgentController(

openhands/llm/bedrock.py

@@ -21,9 +21,8 @@ def list_foundation_models(
         return ['bedrock/' + model['modelId'] for model in model_summaries]
     except Exception as err:
         logger.warning(
-            '%s. Please config AWS_REGION_NAME AWS_ACCESS_KEY_ID AWS_SECRET_ACCESS_KEY'
+            f'{err}. Please config AWS_REGION_NAME AWS_ACCESS_KEY_ID AWS_SECRET_ACCESS_KEY'
             ' if you want use bedrock model.',
-            err,
         )
         return []
 

openhands/llm/llm.py

@@ -37,7 +37,7 @@ from openhands.core.exceptions import (
     OperationCancelled,
     UserCancelledError,
 )
-from openhands.core.logger import llm_prompt_logger, llm_response_logger
+from openhands.core.logger import get_llm_loggers
 from openhands.core.logger import openhands_logger as logger
 from openhands.core.message import Message
 from openhands.core.metrics import Metrics
@@ -52,6 +52,8 @@ cache_prompting_supported_models = [
     'claude-3-haiku-20240307',
 ]
 
+llm_prompt_logger, llm_response_logger = get_llm_loggers().values()
+
 
 class LLM:
     """The LLM class represents a Language Model instance.
@@ -651,7 +653,7 @@ class LLM:
                 input_cost_per_token=self.config.input_cost_per_token,
                 output_cost_per_token=self.config.output_cost_per_token,
             )
-            logger.info(f'Using custom cost per token: {cost_per_token}')
+            logger.debug(f'Using custom cost per token: {cost_per_token}')
             extra_kwargs['custom_cost_per_token'] = cost_per_token
 
         if not self.is_local():

openhands/memory/condenser.py

@@ -18,7 +18,7 @@ class MemoryCondenser:
             summary_response = resp['choices'][0]['message']['content']
             return summary_response
         except Exception as e:
-            logger.error('Error condensing thoughts: %s', str(e), exc_info=False)
+            logger.error(f'Error condensing thoughts: {e}', exc_info=False)
 
             # TODO If the llm fails with ContextWindowExceededError, we can try to condense the memory chunk by chunk
             raise

openhands/memory/memory.py

@@ -161,7 +161,7 @@ class LongTermMemory:
             },
         )
         self.thought_idx += 1
-        logger.debug('Adding %s event to memory: %d', t, self.thought_idx)
+        logger.debug(f'Adding {t} event to memory: {self.thought_idx}')
         thread = threading.Thread(target=self._add_doc, args=(doc,))
         self._add_threads.append(thread)
         thread.start()  # We add the doc concurrently so we don't have to wait ~500ms for the insert

openhands/runtime/browser/browser_env.py

@@ -171,7 +171,7 @@ class BrowserEnv:
             response_id, _ = self.agent_side.recv()
             if response_id == 'ALIVE':
                 return True
-            logger.info(f'Browser env is not alive. Response ID: {response_id}')
+            logger.debug(f'Browser env is not alive. Response ID: {response_id}')
 
     def close(self):
         if not self.process.is_alive():

openhands/runtime/builder/docker.py

@@ -30,14 +30,14 @@ class DockerRuntimeBuilder(RuntimeBuilder):
         previous_layer_count = 0
         for log in build_logs:
             if 'stream' in log:
-                logger.info(log['stream'].strip())
+                logger.debug(log['stream'].strip())
             elif 'error' in log:
                 logger.error(log['error'].strip())
             elif 'status' in log:
                 self._output_build_progress(log, layers, previous_layer_count)
                 previous_layer_count = len(layers)
             else:
-                logger.info(str(log))
+                logger.debug(str(log))
 
         logger.info(f'Image [{target_image_hash_name}] build finished.')
 
@@ -80,14 +80,14 @@ class DockerRuntimeBuilder(RuntimeBuilder):
             return False
 
         try:
-            logger.info(f'Checking, if image exists locally:\n{image_name}')
             self.docker_client.images.get(image_name)
-            logger.info('Image found locally.')
+            logger.info(f'Image found locally:\n{image_name}')
             return True
         except docker.errors.ImageNotFound:
             try:
                 logger.info(
-                    'Image not found locally. Trying to pull it, please wait...'
+                    f'Image not found locally: {image_name}.\n'
+                    'Trying to pull it, please wait...'
                 )
 
                 layers: dict[str, dict[str, str]] = {}
@@ -97,7 +97,7 @@ class DockerRuntimeBuilder(RuntimeBuilder):
                 ):
                     self._output_build_progress(line, layers, previous_layer_count)
                     previous_layer_count = len(layers)
-                logger.info('Image pulled')
+                logger.debug('Image pulled')
                 return True
             except docker.errors.ImageNotFound:
                 logger.info('Could not find image locally or in registry.')

openhands/runtime/client/client.py

@@ -95,7 +95,7 @@ class RuntimeClient:
         for plugin in self.plugins_to_load:
             await plugin.initialize(self.username)
             self.plugins[plugin.name] = plugin
-            logger.info(f'Initializing plugin: {plugin.name}')
+            logger.debug(f'Initializing plugin: {plugin.name}')
 
             if isinstance(plugin, JupyterPlugin):
                 await self.run_ipython(
@@ -111,7 +111,7 @@ class RuntimeClient:
                     code='from openhands.runtime.plugins.agent_skills.agentskills import *\n'
                 )
             )
-            logger.info(f'AgentSkills initialized: {obs}')
+            logger.debug(f'AgentSkills initialized: {obs}')
 
         await self._init_bash_commands()
         logger.info('Runtime client initialized.')
@@ -136,7 +136,7 @@ class RuntimeClient:
         """
 
         # First create the working directory, independent of the user
-        logger.info(f'Client working directory: {self.initial_pwd}')
+        logger.debug(f'Client working directory: {self.initial_pwd}')
         command = f'umask 002; mkdir -p {self.initial_pwd}'
         output = subprocess.run(command, shell=True, capture_output=True)
         out_str = output.stdout.decode()
@@ -237,7 +237,7 @@ class RuntimeClient:
         self.shell.expect(self.__bash_expect_regex)
 
     async def _init_bash_commands(self):
-        logger.info(f'Initializing by running {len(INIT_COMMANDS)} bash commands...')
+        logger.debug(f'Initializing by running {len(INIT_COMMANDS)} bash commands...')
         for command in INIT_COMMANDS:
             action = CmdRunAction(command=command)
             action.timeout = 300
@@ -248,7 +248,7 @@ class RuntimeClient:
             )
             assert obs.exit_code == 0
 
-        logger.info('Bash init commands completed')
+        logger.debug('Bash init commands completed')
 
     def _get_bash_prompt_and_update_pwd(self):
         ps1 = self.shell.after
@@ -753,7 +753,8 @@ if __name__ == '__main__':
             logger.error(f'Error listing files: {e}', exc_info=True)
             return []
 
-    logger.info('Runtime client initialized.')
-
-    logger.info(f'Starting action execution API on port {args.port}')
+    logger.info(
+        f'Runtime client initialized.'
+        f'Starting action execution API on port {args.port}'
+    )
     run(app, host='0.0.0.0', port=args.port)

openhands/runtime/client/runtime.py

@@ -153,9 +153,11 @@ class EventStreamRuntime(Runtime):
                 f'Installing extra user-provided dependencies in the runtime image: {self.config.sandbox.runtime_extra_deps}'
             )
 
-        self.skip_container_logs = (
-            os.environ.get('SKIP_CONTAINER_LOGS', 'false').lower() == 'true'
-        )
+        # container logs can be skipped by setting the SKIP_CONTAINER_LOGS env var to true or 1
+        self.skip_container_logs = os.getenv(
+            'SKIP_CONTAINER_LOGS', 'false'
+        ).lower() in ['true', '1']
+
         if self.runtime_container_image is None:
             if self.base_container_image is None:
                 raise ValueError(
@@ -291,7 +293,7 @@ class EventStreamRuntime(Runtime):
                 volumes=volumes,
             )
             self.log_buffer = LogBuffer(container)
-            logger.info(f'Container started. Server url: {self.api_url}')
+            logger.debug(f'Container started. Server url: {self.api_url}')
             self.send_status_message('STATUS$CONTAINER_STARTED')
             return container
         except Exception as e:
@@ -508,7 +510,7 @@ class EventStreamRuntime(Runtime):
         finally:
             if recursive:
                 os.unlink(temp_zip_path)
-            logger.info(f'Copy completed: host:{host_src} -> runtime:{sandbox_dest}')
+            logger.debug(f'Copy completed: host:{host_src} -> runtime:{sandbox_dest}')
             self._refresh_logs()
 
     def list_files(self, path: str | None = None) -> list[str]:

openhands/runtime/remote/runtime.py

@@ -246,7 +246,7 @@ class RemoteRuntime(Runtime):
             assert action.timeout is not None
 
             try:
-                logger.info('Executing action')
+                logger.debug('Executing action')
                 request_body = {'action': event_to_dict(action)}
                 logger.debug(f'Request body: {request_body}')
                 response = send_request(
@@ -338,7 +338,7 @@ class RemoteRuntime(Runtime):
                 ),
             )
             if response.status_code == 200:
-                logger.info(
+                logger.debug(
                     f'Copy completed: host:{host_src} -> runtime:{sandbox_dest}. Response: {response.text}'
                 )
                 return
@@ -352,7 +352,7 @@ class RemoteRuntime(Runtime):
         finally:
             if recursive:
                 os.unlink(temp_zip_path)
-            logger.info(f'Copy completed: host:{host_src} -> runtime:{sandbox_dest}')
+            logger.debug(f'Copy completed: host:{host_src} -> runtime:{sandbox_dest}')
 
     def list_files(self, path: str | None = None) -> list[str]:
         self._wait_until_alive()

openhands/runtime/runtime.py

@@ -92,7 +92,7 @@ class Runtime:
                 code += f'os.environ["{key}"] = {json.dumps(value)}\n'
             code += '\n'
             obs = self.run_ipython(IPythonRunCellAction(code))
-            logger.info(f'Added env vars to IPython: code={code}, obs={obs}')
+            logger.debug(f'Added env vars to IPython: code={code}, obs={obs}')
 
         # Add env vars to the Bash shell
         cmd = ''

openhands/runtime/utils/runtime_build.py

@@ -43,7 +43,7 @@ def _put_source_code_to_dir(temp_dir: str):
         raise RuntimeError(f'Temp directory {temp_dir} does not exist')
 
     project_root = os.path.dirname(os.path.dirname(os.path.abspath(openhands.__file__)))
-    logger.info(f'Building source distribution using project root: {project_root}')
+    logger.debug(f'Building source distribution using project root: {project_root}')
 
     # Fetch the correct version from pyproject.toml
     package_version = _get_package_version()
@@ -60,7 +60,7 @@ def _put_source_code_to_dir(temp_dir: str):
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
     )
-    logger.info(result.stdout.decode())
+    logger.debug(result.stdout.decode())
     err_logs = result.stderr.decode()
     if err_logs:
         logger.error(err_logs)
@@ -72,7 +72,7 @@ def _put_source_code_to_dir(temp_dir: str):
     if not os.path.exists(tarball_path):
         logger.error(f'Source distribution not found at {tarball_path}')
         raise RuntimeError(f'Source distribution not found at {tarball_path}')
-    logger.info(f'Source distribution created at {tarball_path}')
+    logger.debug(f'Source distribution created at {tarball_path}')
 
     # Unzip the tarball
     shutil.unpack_archive(tarball_path, temp_dir)
@@ -83,7 +83,7 @@ def _put_source_code_to_dir(temp_dir: str):
         os.path.join(temp_dir, f'openhands_ai-{package_version}'),
         os.path.join(temp_dir, 'code'),
     )
-    logger.info(f'Unpacked source code directory: {os.path.join(temp_dir, "code")}')
+    logger.debug(f'Unpacked source code directory: {os.path.join(temp_dir, "code")}')
 
 
 def _generate_dockerfile(
@@ -142,7 +142,9 @@ def prep_docker_build_folder(
         skip_init=skip_init,
         extra_deps=extra_deps,
     )
-    if os.getenv('SKIP_CONTAINER_LOGS', 'false') != 'true':
+
+    # Write or skip container logs
+    if os.getenv('SKIP_CONTAINER_LOGS', 'false').lower() not in ['true', '1']:
         logger.debug(
             (
                 f'===== Dockerfile content start =====\n'
@@ -155,7 +157,7 @@ def prep_docker_build_folder(
 
     # Get the MD5 hash of the dir_path directory
     dist_hash = dirhash(dir_path, 'md5')
-    logger.info(
+    logger.debug(
         f'Input base image: {base_image}\n'
         f'Skip init: {skip_init}\n'
         f'Extra deps: {extra_deps}\n'
@@ -451,7 +453,7 @@ if __name__ == '__main__':
     else:
         # If a build_folder is not provided, after copying the required source code and dynamically creating the
         # Dockerfile, we actually build the Docker image
-        logger.info('Building image in a temporary folder')
+        logger.debug('Building image in a temporary folder')
         docker_builder = DockerRuntimeBuilder(docker.from_env())
         image_name = build_runtime_image(args.base_image, docker_builder)
         print(f'\nBUILT Image: {image_name}\n')

openhands/security/analyzer.py

@@ -24,7 +24,7 @@ class SecurityAnalyzer:
 
     async def on_event(self, event: Event) -> None:
         """Handles the incoming event, and when Action is received, analyzes it for security risks."""
-        logger.info(f'SecurityAnalyzer received event: {event}')
+        logger.debug(f'SecurityAnalyzer received event: {event}')
         await self.log_event(event)
         if not isinstance(event, Action):
             return

openhands/security/invariant/analyzer.py

@@ -150,7 +150,7 @@ class InvariantAnalyzer(SecurityAnalyzer):
             self.event_stream.add_event(new_event, EventSource.AGENT)
 
     async def security_risk(self, event: Action) -> ActionSecurityRisk:
-        logger.info('Calling security_risk on InvariantAnalyzer')
+        logger.debug('Calling security_risk on InvariantAnalyzer')
         new_elements = parse_element(self.trace, event)
         input = [e.model_dump(exclude_none=True) for e in new_elements]  # type: ignore [call-overload]
         self.trace.extend(new_elements)

openhands/server/auth/auth.py

@@ -26,7 +26,7 @@ def get_sid_from_token(token: str, jwt_secret: str) -> str:
     except InvalidTokenError:
         logger.error('Invalid token')
     except Exception as e:
-        logger.exception('Unexpected error decoding token: %s', e)
+        logger.exception(f'Unexpected error decoding token: {e}')
     return ''
 
 

openhands/server/session/agent_session.py

@@ -196,5 +196,5 @@ class AgentSession:
             )
             logger.info(f'Restored agent state from session, sid: {self.sid}')
         except Exception as e:
-            logger.info(f'State could not be restored: {e}')
+            logger.debug(f'State could not be restored: {e}')
         logger.info('Agent controller initialized.')

openhands/server/session/session.py

@@ -65,10 +65,10 @@ class Session:
                 await self.dispatch(data)
         except WebSocketDisconnect:
             await self.close()
-            logger.info('WebSocket disconnected, sid: %s', self.sid)
+            logger.info(f'WebSocket disconnected, sid: {self.sid}')
         except RuntimeError as e:
             await self.close()
-            logger.exception('Error in loop_recv: %s', e)
+            logger.exception(f'Error in loop_recv: {e}')
 
     async def _initialize_agent(self, data: dict):
         self.agent_session.event_stream.add_event(

tests/unit/test_condenser.py

@@ -40,5 +40,5 @@ def test_condense_logs_error(mock_logger, memory_condenser, mock_llm):
     with pytest.raises(LLMResponseError):
         memory_condenser.condense('Summarize this', mock_llm)
     mock_logger.error.assert_called_once_with(
-        'Error condensing thoughts: %s', 'LLM error', exc_info=False
+        'Error condensing thoughts: LLM error', exc_info=False
     )