{
 "cells": [
  {
   "cell_type": "markdown",
   "id": "801ebbba",
   "metadata": {},
   "source": [
    "# Log messages\n",
    "\n",
    "[![Click and Open In Colab](https://colab.research.google.com/assets/colab-badge.svg)](https://colab.research.google.com/github/metadriverse/metaurban/blob/main/documentation/source/log_msg.ipynb)\n",
    "\n",
    "\n",
    "Logging message is important to oversee the program status. metaurban adopts Python's `logging` module to log messages. "
   ]
  },
  {
   "cell_type": "markdown",
   "id": "443f8317",
   "metadata": {},
   "source": [
    "## Global logger \n",
    "We provide a wrapper in `metaurban/engine/logger` to customize some features. We recommend using it to log messages to make the logging consistent. It is a global variable, so you can get the logger at anywhere of your code. Some classes like `BaseEnv` may have a variable called `logger` as well, which is actually the same as the global logger."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "id": "a08dffbc",
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "\u001b[38;20m[INFO] Create environment\n",
      "\u001b[0m\n",
      "\u001b[38;20m[INFO] Environment: BaseEnv\u001b[0m\n",
      "\u001b[38;20m[INFO] MetaUrban version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Sensors: [lidar: Lidar(), side_detector: SideDetector(), lane_line_detector: LaneLineDetector()]\u001b[0m\n",
      "\u001b[38;20m[INFO] Render Mode: none\u001b[0m\n",
      "\u001b[38;20m[INFO] Horizon (Max steps per agent): None\u001b[0m\n",
      "\u001b[33;20m[WARNING] You are using DummyObservation which doesn't collect information from the environment. (observation_base.py:50)\u001b[0m\n",
      "\u001b[38;20m[INFO] Reset environment\u001b[0m\n",
      "\u001b[38;20m[INFO] Assets version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Known Pipes: glxGraphicsPipe\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[38;20m[INFO] Start Scenario Index: 0, Num Scenarios : 1\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[33;20m[WARNING] No map is provided. Set vehicle to position (0, 0) with heading 0 (base_vehicle.py:316)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Reward function is not implemented. Return reward = 0 (base_env.py:478)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Done function is not implemented. Return Done = False (base_env.py:486)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Cost function is not implemented. Return cost = 0 (base_env.py:482)\u001b[0m\n",
      "\u001b[38;20m[INFO] Simulate step 0\u001b[0m\n",
      "\u001b[38;20m[INFO] Simulate step 1\u001b[0m\n",
      "\u001b[38;20m[INFO] Simulate step 2\u001b[0m\n",
      "\u001b[38;20m[INFO] Simulate step 3\u001b[0m\n",
      "\u001b[38;20m[INFO] Simulate step 4\u001b[0m\n",
      "\u001b[38;20m[INFO] Close environment\u001b[0m\n"
     ]
    }
   ],
   "source": [
    "from metaurban.envs.base_env import BaseEnv\n",
    "from metaurban.engine.logger import get_logger # get_logger\n",
    "\n",
    "logger = get_logger()\n",
    "\n",
    "# create environment\n",
    "logger.info(\"Create environment\\n\")\n",
    "env = BaseEnv(dict(use_render=False))\n",
    "assert logger is env.logger # the environment.logger is the same as global logger\n",
    "\n",
    "# reset environment\n",
    "logger.info(\"Reset environment\")\n",
    "env.reset()\n",
    "try:\n",
    "    for i in range(5):\n",
    "        logger.info(\"Simulate step {}\".format(i))\n",
    "        env.step(env.action_space.sample())\n",
    "finally:\n",
    "    logger.info(\"Close environment\")\n",
    "    env.close()\n"
   ]
  },
  {
   "cell_type": "markdown",
   "id": "a8f87467",
   "metadata": {},
   "source": [
    "The logger can be used at everywhere. For example, it can be used in your manager."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "id": "39443673",
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "\u001b[38;20m[INFO] Environment: BaseEnv\u001b[0m\n",
      "\u001b[38;20m[INFO] MetaUrban version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Sensors: [lidar: Lidar(), side_detector: SideDetector(), lane_line_detector: LaneLineDetector()]\u001b[0m\n",
      "\u001b[38;20m[INFO] Render Mode: none\u001b[0m\n",
      "\u001b[38;20m[INFO] Horizon (Max steps per agent): None\u001b[0m\n",
      "\u001b[33;20m[WARNING] You are using DummyObservation which doesn't collect information from the environment. (observation_base.py:50)\u001b[0m\n",
      "\u001b[38;20m[INFO] Assets version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Known Pipes: glxGraphicsPipe\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[38;20m[INFO] Start Scenario Index: 0, Num Scenarios : 1\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[33;20m[WARNING] No map is provided. Set vehicle to position (0, 0) with heading 0 (base_vehicle.py:316)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Reward function is not implemented. Return reward = 0 (base_env.py:478)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Done function is not implemented. Return Done = False (base_env.py:486)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Cost function is not implemented. Return cost = 0 (base_env.py:482)\u001b[0m\n",
      "\u001b[38;20m[INFO] Init MyMgr...\u001b[0m\n",
      "\u001b[38;20m[INFO] Step 1...\u001b[0m\n",
      "\u001b[38;20m[INFO] Step 2...\u001b[0m\n",
      "\u001b[38;20m[INFO] Step 3...\u001b[0m\n",
      "\u001b[38;20m[INFO] Step 4...\u001b[0m\n",
      "\u001b[38;20m[INFO] Step 5...\u001b[0m\n"
     ]
    }
   ],
   "source": [
    "from metaurban.envs.base_env import BaseEnv\n",
    "from metaurban.engine.logger import get_logger # get_logger\n",
    "from metaurban.manager.base_manager import BaseManager\n",
    "\n",
    "logger = get_logger()\n",
    "\n",
    "class MyMgr(BaseManager):\n",
    "    \n",
    "    def __init__(self):\n",
    "        super(MyMgr, self).__init__()\n",
    "        logger.info(\"Init MyMgr...\")\n",
    "    \n",
    "    def after_step(self):\n",
    "        logger.info(\"Step {}...\".format(self.episode_step))\n",
    "        return dict()\n",
    "\n",
    "\n",
    "# create environment\n",
    "env = BaseEnv(dict(use_render=False))\n",
    "\n",
    "# reset environment\n",
    "env.reset()\n",
    "\n",
    "# add manager\n",
    "env.engine.register_manager(\"my_mgr\", MyMgr())\n",
    "try:\n",
    "    for i in range(5):\n",
    "        env.step(env.action_space.sample())\n",
    "finally:\n",
    "    env.close()"
   ]
  },
  {
   "cell_type": "markdown",
   "id": "98b765f0",
   "metadata": {},
   "source": [
    "## Log level\n",
    "Similar to `logging` module, one can change the log level to decide which log messages to be printed. Generally, MetaUrban uses `logging.INFO`, `logging.DEBUG`, and `logging.WARNING` to classify log messages. By default, the log level is `logging.INFO` and thus debug messages will be hidden. The log level can be set in environment config. The following example shows how to print more debug message by setting `log_level=logging.DEBUG`. In addition, if `debug=True` in the environment config, the log level will be set to `logging.DEBUG` as well. "
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "id": "0c77a550",
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "\u001b[38;20m[INFO] Environment: BaseEnv\u001b[0m\n",
      "\u001b[38;20m[INFO] MetaUrban version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Sensors: [lidar: Lidar(), side_detector: SideDetector(), lane_line_detector: LaneLineDetector()]\u001b[0m\n",
      "\u001b[38;20m[INFO] Render Mode: none\u001b[0m\n",
      "\u001b[38;20m[INFO] Horizon (Max steps per agent): None\u001b[0m\n",
      "\u001b[33;20m[WARNING] You are using DummyObservation which doesn't collect information from the environment. (observation_base.py:50)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Reset environment (84640474.py:12)\u001b[0m\n",
      "\u001b[38;20m[INFO] Assets version: 0.0.1\u001b[0m\n",
      "\u001b[38;20m[INFO] Known Pipes: glxGraphicsPipe\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Load Vehicle Module: Lidar (distance_detector.py:115)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Load Vehicle Module: SideDetector (distance_detector.py:115)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Load Vehicle Module: LaneLineDetector (distance_detector.py:115)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[38;20m[INFO] Start Scenario Index: 0, Num Scenarios : 1\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[33;20m[WARNING] No map is provided. Set vehicle to position (0, 0) with heading 0 (base_vehicle.py:316)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] DefaultVehicle is attached to the world. (base_object.py:237)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Terrain is attached to the world. (base_object.py:237)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Reward function is not implemented. Return reward = 0 (base_env.py:478)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Done function is not implemented. Return Done = False (base_env.py:486)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Cost function is not implemented. Return cost = 0 (base_env.py:482)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Simulate step 0 (84640474.py:16)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Simulate step 1 (84640474.py:16)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Simulate step 2 (84640474.py:16)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Simulate step 3 (84640474.py:16)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Simulate step 4 (84640474.py:16)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Close environment (84640474.py:19)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] DefaultVehicle is detached from the world. (base_object.py:255)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Finish cleaning 6 node path for DefaultVehicle. (base_object.py:286)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Before del taskMgr: task_chain_num=2, all_tasks=[PythonTask resetPrevTransform, PythonTask dataLoop, PythonTask eventManager, PythonTask ivalLoop, PythonTask collisionLoop, PythonTask igLoop] (engine_core.py:389)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] After del taskMgr: task_chain_num=2, all_tasks=[PythonTask resetPrevTransform, PythonTask dataLoop, PythonTask eventManager, PythonTask ivalLoop, PythonTask collisionLoop, PythonTask igLoop] (engine_core.py:397)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Terrain is detached from the world. (base_object.py:255)\u001b[0m\n",
      "\u001b[38;20m[DEBUG] Finish cleaning 1 node path for Terrain. (base_object.py:286)\u001b[0m\n"
     ]
    }
   ],
   "source": [
    "from metaurban.envs.base_env import BaseEnv\n",
    "import logging\n",
    "from metaurban.engine.logger import get_logger # get_logger\n",
    "\n",
    "logger = get_logger()\n",
    "\n",
    "# create environment\n",
    "env = BaseEnv(dict(use_render=False, log_level=logging.DEBUG))\n",
    "assert logger is env.logger # the environment.logger is the same as global logger\n",
    "\n",
    "# reset environment\n",
    "logger.debug(\"Reset environment\")\n",
    "env.reset()\n",
    "try:\n",
    "    for i in range(5):\n",
    "        logger.debug(\"Simulate step {}\".format(i))\n",
    "        env.step(env.action_space.sample())\n",
    "finally:\n",
    "    logger.debug(\"Close environment\")\n",
    "    env.close()"
   ]
  },
  {
   "cell_type": "markdown",
   "id": "312cc6dc",
   "metadata": {},
   "source": [
    "If you would like to turn off all log messages, changing the log_level to `logging.WARNING` (or `logging.CRITICAL`) can suppress messages logged by `logging.info()`, `logging.debug()` (or even `logging.warn`)."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "id": "ed56a0c4",
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Can not find `start_seed` or `start_scenario_index`. Use 0 as `start_seed` (base_engine.py:577)\u001b[0m\n",
      "\u001b[33;20m[WARNING] No map is provided. Set vehicle to position (0, 0) with heading 0 (base_vehicle.py:316)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Reward function is not implemented. Return reward = 0 (base_env.py:478)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Done function is not implemented. Return Done = False (base_env.py:486)\u001b[0m\n",
      "\u001b[33;20m[WARNING] Cost function is not implemented. Return cost = 0 (base_env.py:482)\u001b[0m\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "Turn off all messages...\n"
     ]
    }
   ],
   "source": [
    "from metaurban.engine.logger import set_log_level # get_logger\n",
    "\n",
    "def run(): # define the simulation loop\n",
    "    # reset environment\n",
    "    logger.debug(\"Reset environment\")\n",
    "    env.reset()\n",
    "    try:\n",
    "        for i in range(5):\n",
    "            logger.debug(\"Simulate step {}\".format(i))\n",
    "            env.step(env.action_space.sample())\n",
    "    finally:\n",
    "        logger.debug(\"Close environment\")\n",
    "        env.close()\n",
    "\n",
    "set_log_level(logging.WARNING) # Or set it in environment config\n",
    "run()\n",
    "\n",
    "\n",
    "print(\"Turn off all messages...\")    \n",
    "\n",
    "set_log_level(logging.CRITICAL) # Or set it in environment config\n",
    "run()"
   ]
  },
  {
   "cell_type": "markdown",
   "id": "3c3e6834",
   "metadata": {},
   "source": [
    "## Log once\n",
    "Sometimes, we may want the message to be logged only once in one episode. In this case, we can use the `log_once` key to notify the logger to show some messages only once until the next `reset` is called."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "id": "28b15685",
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "\u001b[31;1m[CRITICAL] Step... (I will only show once) (4102420745.py:11)\u001b[0m\n"
     ]
    }
   ],
   "source": [
    "from metaurban.envs.base_env import BaseEnv\n",
    "import logging\n",
    "\n",
    "# create environment\n",
    "env = BaseEnv(dict(use_render=False, log_level=logging.CRITICAL))\n",
    "\n",
    "# reset environment\n",
    "env.reset()\n",
    "try:\n",
    "    for i in range(5):\n",
    "        env.logger.critical(\"Step... (I will only show once)\".format(i), extra={\"log_once\": True})\n",
    "        env.step(env.action_space.sample())\n",
    "finally:\n",
    "    env.close()\n"
   ]
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "metaurban",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.10.16"
  },
  "mystnb": {
   "execution_mode": "off"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 5
}