Merge pull request #59 from adf-python/feature/logger

ロガーを整備する

Author: shima004

adf_core_python/core/agent/platoon/platoon.py

@@ -1,5 +1,3 @@
-from logging import Logger, getLogger
-
 from rcrs_core.agents.agent import Agent
 from rcrs_core.commands.Command import Command
 from rcrs_core.config.config import Config as RCRSConfig
@@ -16,6 +14,7 @@
 from adf_core_python.core.agent.precompute.precompute_data import PrecomputeData
 from adf_core_python.core.component.tactics.tactics_agent import TacticsAgent
 from adf_core_python.core.config.config import Config
+from adf_core_python.core.logger.logger import get_agent_logger
 
 
 class Platoon(Agent):
@@ -41,11 +40,15 @@ def __init__(
         self._develop_data = develop_data
 
     def post_connect(self) -> None:
-        self._logger: Logger = getLogger(__name__)
         self._agent_info: AgentInfo = AgentInfo(self, self.world_model)
         self._world_info: WorldInfo = WorldInfo(self.world_model)
         self._precompute_data: PrecomputeData = PrecomputeData(self._data_storage_name)
 
+        self._logger = get_agent_logger(
+            f"{self.__class__.__module__}.{self.__class__.__qualname__}",
+            self._agent_info,
+        )
+
         if self._is_precompute:
             self._mode = Mode.PRECOMPUTATION
         else:
@@ -106,6 +109,9 @@ def post_connect(self) -> None:
     def think(self, time: int, change_set: ChangeSet, hear: list[Command]) -> None:
         self._agent_info.set_change_set(change_set)
         self._world_info.set_change_set(change_set)
+        self._agent_info.set_time(time)
+        self._agent_info.set_heard_commands(hear)
+
         action: Action = self._tactics_agent.think(
             self._agent_info,
             self._world_info,

adf_core_python/core/component/tactics/tactics_agent.py

@@ -3,6 +3,8 @@
 from abc import ABC, abstractmethod
 from typing import TYPE_CHECKING, Any, Optional
 
+from adf_core_python.core.logger.logger import get_agent_logger
+
 if TYPE_CHECKING:
     from adf_core_python.core.agent.action.action import Action
     from adf_core_python.core.agent.communication.message_manager import MessageManager
@@ -34,7 +36,9 @@ def initialize(
         message_manager: MessageManager,
         develop_data: DevelopData,
     ) -> None:
-        raise NotImplementedError
+        self._logger = get_agent_logger(
+            f"{self.__class__.__module__}.{self.__class__.__qualname__}", agent_info
+        )
 
     @abstractmethod
     def precompute(

adf_core_python/core/launcher/agent_launcher.py

@@ -1,6 +1,5 @@
 import importlib
 import threading
-from logging import Logger, getLogger
 
 from rcrs_core.connection.componentLauncher import ComponentLauncher
 
@@ -15,6 +14,7 @@
 from adf_core_python.core.launcher.connect.connector_ambulance_team import (
     ConnectorAmbulanceTeam,
 )
+from adf_core_python.core.logger.logger import get_logger
 
 # from adf_core_python.core.launcher.connect.connector_fire_brigade import (
 #     ConnectorFireBrigade,
@@ -33,7 +33,7 @@
 class AgentLauncher:
     def __init__(self, config: Config):
         self.config = config
-        self.logger: Logger = getLogger(__name__)
+        self.logger = get_logger(__name__)
         self.connectors: list[Connector] = []
         self.thread_list: list[threading.Thread] = []
 
@@ -67,14 +67,9 @@ def launch(self) -> None:
         for connector in self.connectors:
             threads = connector.connect(component_launcher, self.config, self.loader)
             for thread in threads:
+                thread.daemon = True
                 thread.start()
             self.thread_list.extend(threads)
 
         for thread in self.thread_list:
             thread.join()
-
-        connected_agent_count = 0
-        for connector in self.connectors:
-            connected_agent_count += connector.get_connected_agent_count()
-
-        self.logger.info(f"Connected agent count: {connected_agent_count}")

adf_core_python/core/launcher/connect/connector_ambulance_team.py

@@ -1,5 +1,4 @@
 import threading
-from logging import Logger, getLogger
 
 from rcrs_core.connection.componentLauncher import ComponentLauncher
 
@@ -13,12 +12,13 @@
 from adf_core_python.core.config.config import Config
 from adf_core_python.core.launcher.config_key import ConfigKey
 from adf_core_python.core.launcher.connect.connector import Connector
+from adf_core_python.core.logger.logger import get_logger
 
 
 class ConnectorAmbulanceTeam(Connector):
     def __init__(self) -> None:
         super().__init__()
-        self.logger: Logger = getLogger(__name__)
+        self.logger = get_logger(__name__)
 
     def connect(
         self,

adf_core_python/core/logger/logger.py

@@ -0,0 +1,80 @@
+import logging
+import sys
+
+import structlog
+from structlog.dev import ConsoleRenderer
+from structlog.processors import JSONRenderer
+
+from adf_core_python.core.agent.info.agent_info import AgentInfo
+
+
+def get_logger(name: str) -> structlog.BoundLogger:
+    """
+    Get a logger with the given name.
+    For kernel logging, use this function to get a logger.
+
+    Parameters
+    ----------
+    name : str
+        The name of the logger.
+
+    Returns
+    -------
+    structlog.BoundLogger
+        The logger with the given name.
+    """
+    return structlog.get_logger(name)
+
+
+def get_agent_logger(name: str, agent_info: AgentInfo) -> structlog.BoundLogger:
+    """
+    Get a logger with the given name and agent information.
+    For agent logging, use this function to get a logger.
+
+    Parameters
+    ----------
+    name : str
+        The name of the logger.
+    agent_info : AgentInfo
+        The agent information.
+
+    Returns
+    -------
+    structlog.BoundLogger
+        The logger with the given name and agent information.
+    """
+    return structlog.get_logger(name).bind(
+        agent_id=str(agent_info.get_entity_id()),
+        agent_type=str(agent_info.get_myself().get_urn().name),
+    )
+
+
+def configure_logger() -> None:
+    structlog.configure(
+        processors=[
+            structlog.stdlib.add_log_level,
+            structlog.stdlib.add_logger_name,
+            structlog.stdlib.PositionalArgumentsFormatter(),
+            structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M.%S", utc=False),
+            structlog.processors.StackInfoRenderer(),
+            structlog.processors.UnicodeDecoder(),
+            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        wrapper_class=structlog.stdlib.BoundLogger,
+        cache_logger_on_first_use=True,
+    )
+    handler_stdout = logging.StreamHandler(sys.stdout)
+    handler_stdout.setFormatter(
+        structlog.stdlib.ProcessorFormatter(processor=ConsoleRenderer())
+    )
+
+    handler_file = logging.FileHandler("agent.log")
+    handler_file.setFormatter(
+        structlog.stdlib.ProcessorFormatter(processor=JSONRenderer())
+    )
+
+    root_logger = logging.getLogger()
+    root_logger.addHandler(handler_stdout)
+    root_logger.addHandler(handler_file)
+    root_logger.setLevel(logging.DEBUG)

adf_core_python/implement/tactics/default_tactics_ambulance_team.py

@@ -30,6 +30,15 @@ def initialize(
         develop_data: DevelopData,
     ) -> None:
         # world_info.index_class()
+        super().initialize(
+            agent_info,
+            world_info,
+            scenario_info,
+            module_manager,
+            precompute_data,
+            message_manager,
+            develop_data,
+        )
         match scenario_info.get_mode():
             case Mode.NON_PRECOMPUTE:
                 self._search: Search = cast(
@@ -118,6 +127,7 @@ def think(
                 .get_action()
             )
             if action is not None:
+                self._logger.debug(f"action: {action}", time=agent_info.get_time())
                 return action
 
         target_entity_id = self._search.calculate().get_target_entity_id()
@@ -128,6 +138,7 @@ def think(
                 .get_action()
             )
             if action is not None:
+                self._logger.debug(f"action: {action}", time=agent_info.get_time())
                 return action
 
         return ActionRest()

adf_core_python/main.py

@@ -1,13 +1,14 @@
 import argparse
-import logging
 
 from adf_core_python.core.config.config import Config
 from adf_core_python.core.launcher.agent_launcher import AgentLauncher
 from adf_core_python.core.launcher.config_key import ConfigKey
+from adf_core_python.core.logger.logger import configure_logger, get_logger
 
 
 class Main:
     def __init__(self) -> None:
+        self.logger = get_logger(__name__)
         parser = argparse.ArgumentParser(description="Agent Launcher")
 
         parser.add_argument(
@@ -56,32 +57,41 @@ def __init__(self) -> None:
             metavar="",
         )
         parser.add_argument(
-            "--verbose", type=bool, default=False, help="verbose flag", metavar=""
+            "--debug", type=bool, default=False, help="debug flag", metavar=""
         )
         args = parser.parse_args()
-        print(args)
+        self.logger.info(f"Arguments: {args}")
+
         self.config = Config()
         self.config.set_value(ConfigKey.KEY_KERNEL_HOST, args.host)
         self.config.set_value(ConfigKey.KEY_KERNEL_PORT, args.port)
         self.config.set_value(ConfigKey.KEY_AMBULANCE_CENTRE_COUNT, args.ambulance)
         self.config.set_value(ConfigKey.KEY_FIRE_STATION_COUNT, args.firebrigade)
         self.config.set_value(ConfigKey.KEY_POLICE_OFFICE_COUNT, args.policeforce)
         self.config.set_value(ConfigKey.KEY_PRECOMPUTE, args.precompute)
-        self.config.set_value(ConfigKey.KEY_DEBUG_FLAG, args.verbose)
+        self.config.set_value(ConfigKey.KEY_DEBUG_FLAG, args.debug)
+        self.logger.info(f"Config: {self.config}")
 
     def launch(self) -> None:
         agent_launcher: AgentLauncher = AgentLauncher(
             self.config,
         )
         agent_launcher.init_connector()
-        agent_launcher.launch()
+
+        try:
+            agent_launcher.launch()
+        except KeyboardInterrupt:
+            self.logger.info("Agent launcher interrupted")
+        except Exception as e:
+            self.logger.exception("Agent launcher failed", exc_info=e)
+            raise e
+        self.logger.info("Agent launcher finished")
 
 
 if __name__ == "__main__":
-    logging.basicConfig(
-        level=logging.DEBUG,
-        format="%(threadName)s[%(levelname)s][%(name)s]: %(message)s",
-    )
+    configure_logger()
+    logger = get_logger(__name__)
+    logger.info("Starting the agent launcher")
 
     main = Main()
     main.launch()