fix(logging): add cli output during alabos running

.pylintrc

@@ -143,6 +143,7 @@ disable=fixme,
         broad-exception-caught,
         too-many-positional-arguments,
         broad-exception-raised,
+        logging-fstring-interpolation,
         E0001, R0902, W0702, W1114, W0201, R0401, R0801, R0022, W0613, E0213, C0209, R1720,
         W0105, R0914, R0912, R0915, R1720, R1705, W1113, W0613, W0107, W0212, R1705, W0212,
         R0904, W0212, C0103, E1101, W0621, W0404, C0103, E1101, C0200, W0237, R0911, W0612, 

alab_management/scripts/launch_lab.py

@@ -69,8 +69,12 @@ def launch_resource_manager():
 
 def launch_lab(host, port, debug):
     """Start to run the lab."""
+    import logging
+
     from alab_management.device_view import DeviceView
 
+    logging.basicConfig(level=logging.INFO)
+
     dv = DeviceView()
 
     if len(list(dv.get_all())) == 0:

alab_management/task_actor.py

@@ -4,6 +4,7 @@
 """
 
 import datetime
+import logging
 from traceback import format_exc
 
 import dramatiq
@@ -14,11 +15,15 @@
 from alab_management.logger import DBLogger
 from alab_management.sample_view import SampleView
 from alab_management.task_view import BaseTask, TaskStatus, TaskView
+from alab_management.utils.logger import set_up_rich_handler
 from alab_management.utils.middleware import register_abortable_middleware
 from alab_management.utils.module_ops import load_definition
 
 register_abortable_middleware()
 
+cli_logger = logging.getLogger(__name__)
+set_up_rich_handler(cli_logger)
+
 
 @dramatiq.actor(
     max_retries=0,
@@ -40,6 +45,7 @@ def run_task(task_id_str: str):
     Args:
         task_id_str: The id of the task to run.
     """
+    cli_logger.info(f"Worker starts the task with id: {task_id_str}.")
     from .lab_view import LabView  # pylint: disable=cyclic-import
 
     load_definition()
@@ -128,6 +134,7 @@ def run_task(task_id_str: str):
                 "task_type": task_type.__name__,
             },
         )
+        cli_logger.debug(f"Task {task_id} of type {task_type.__name__} is running.")
         # Following is the line of code that actually runs the task
         # from Alab_one, for eg: Powder dosing. Powder dosing class will have a method "run".
         result = task.run()
@@ -148,6 +155,9 @@ def run_task(task_id_str: str):
                 "traceback": "Task was cancelled due to the abort signal",
             },
         )
+        cli_logger.info(
+            f"Task {task_type} ({task_id}) was cancelled due to the abort signal."
+        )
         lab_view.request_cleanup()
     except:  # noqa: E722
         task_status = TaskStatus.ERROR
@@ -167,6 +177,9 @@ def run_task(task_id_str: str):
                 "traceback": formatted_exception,
             },
         )
+        cli_logger.error(
+            f"Task {task_type} ({task_id}) failed with the following exception: {formatted_exception}"
+        )
         lab_view.request_cleanup()
     else:
         task_status = TaskStatus.COMPLETED
@@ -222,6 +235,7 @@ def run_task(task_id_str: str):
                 "status": "COMPLETED",
             },
         )
+        cli_logger.info(f"Task {task_type} ({task_id}) completed successfully.")
     finally:
         for sample in task_entry["samples"]:
             sample_view.update_sample_task_id(

alab_management/task_manager/task_manager.py

@@ -3,6 +3,7 @@
 which actually executes the tasks.
 """
 
+import logging
 import time
 
 from dramatiq_abort import abort, abort_requested
@@ -11,8 +12,12 @@
 from alab_management.logger import DBLogger
 from alab_management.task_view import TaskView
 from alab_management.task_view.task_enums import CancelingProgress, TaskStatus
+from alab_management.utils.logger import set_up_rich_handler
 from alab_management.utils.module_ops import load_definition
 
+cli_logger = logging.getLogger(__name__)
+set_up_rich_handler(cli_logger)
+
 
 class TaskManager:
     """
@@ -125,6 +130,11 @@ def submit_ready_tasks(self):
                 kwargs={"task_id_str": str(task_entry["task_id"])}
             )
             message_id = result.message_id
+            cli_logger.info(
+                f"Task {task_entry['type']} ({task_entry['task_id']}) sent to actor with message_id {message_id}. "
+                f"A message from Task Actor will be logged with this task_id in alabos launch_worker. If not, "
+                f"there can be an issue with the Dramatiq worker!"
+            )
             self.task_view.set_task_actor_id(
                 task_id=task_entry["task_id"], message_id=message_id
             )
@@ -149,6 +159,10 @@ def handle_tasks_to_be_canceled(self):
                 message_id := task_entry.get("task_actor_id", None)
             ) is not None and abort_requested(message_id=message_id) is None:
                 abort(message_id=message_id)
+                cli_logger.info(
+                    f"Task {task_entry['type']} ({task_entry['task_id']}) is being cancelled. "
+                    f"Task Actor message_id: {message_id}"
+                )
                 self.task_view.update_canceling_progress(
                     task_id=task_entry["task_id"],
                     canceling_progress=CancelingProgress.WORKER_NOTIFIED,

alab_management/utils/logger.py

@@ -0,0 +1,18 @@
+import logging
+
+from rich.console import Console
+from rich.logging import RichHandler
+
+
+def set_up_rich_handler(logger: logging.Logger) -> RichHandler:
+    """Set up a RichHandler for a logger."""
+    rich_handler = RichHandler(
+        rich_tracebacks=True,
+        markup=True,
+        show_path=False,
+        show_level=False,
+        console=Console(force_terminal=True),
+    )
+    rich_handler.setFormatter(logging.Formatter("%(message)s", datefmt="[%X]"))
+    logger.addHandler(rich_handler)
+    return rich_handler

examples/alab_example/submission_script.ipynb

@@ -15,14 +15,6 @@
       "/Users/yuxing/.pyenv/versions/3.10.11/envs/alab_management_new/lib/python3.10/site-packages/paramiko/transport.py:219: CryptographyDeprecationWarning: Blowfish has been deprecated and will be removed in a future release\n",
       "  \"class\": algorithms.Blowfish,\n"
      ]
-    },
-    {
-     "name": "stdout",
-     "output_type": "stream",
-     "text": [
-      "Email alert is not set up due to either missing email_receivers, email_sender or email_password. It is also possible that the system is in simulation mode. Please recheck the config file if this is not expected.\n",
-      "Slack alert is not set up due to either missingslack_bot_token or slack_channel_id. It is also possible that the system is in simulation mode. Please recheck the config file if this is not expected.\n"
-     ]
     }
    ],
    "source": [
@@ -50,7 +42,7 @@
     "# Define the samples\n",
     "# the experiment is to synthesize Li-Mn-O with different ratio of Li2CO3 and MnO\n",
     "samples = [\n",
-    "    exp.add_sample(f\"tutorial_sample_{i}\", tags=[\"tutorial\"], precursors={\"Li2CO3\": (i - 1) / 15, \"MnO\": 1 - (i - 1) / 15}) for i in range(1, 17)\n",
+    "    exp.add_sample(f\"tutorial_sample_{i}\", tags=[\"tutorial\"], precursors={\"Li2CO3\": (i - 1) / 15 + 0.1, \"MnO\": 1 - (i - 1) / 15 + 0.1}) for i in range(1, 17)\n",
     "]\n",
     "\n",
     "# Define the steps\n",
@@ -76,6 +68,35 @@
     "    ending = Ending()\n",
     "    ending.add_to(sample)"
    ]
+  },
+  {
+   "cell_type": "code",
+   "execution_count": 3,
+   "id": "941bdbe9",
+   "metadata": {},
+   "outputs": [
+    {
+     "data": {
+      "text/plain": [
+       "ObjectId('671742595cadc1600784540e')"
+      ]
+     },
+     "execution_count": 3,
+     "metadata": {},
+     "output_type": "execute_result"
+    }
+   ],
+   "source": [
+    "exp.submit()"
+   ]
+  },
+  {
+   "cell_type": "code",
+   "execution_count": null,
+   "id": "5b043ba5",
+   "metadata": {},
+   "outputs": [],
+   "source": []
   }
  ],
  "metadata": {

pyproject.toml

@@ -51,6 +51,7 @@ dependencies = [
     "slack_sdk>=3.19.5",
     "Flask-Cors>=3.0.10",
     "retry>=0.9.2",
+    "rich>=13.9.2",
 ]
 
 [project.optional-dependencies]
@@ -66,7 +67,7 @@ docs = [
     "sphinx_book_theme==1.1.3",
     "myst-nb==1.1.1",
     "sphinx-design==0.6.0",
-    "sphinxcontrib-mermaid==0.9.2"
+    "sphinxcontrib-mermaid==0.9.2",
 ]
 dev = [
     "pre-commit>=2.12.1",
@@ -82,7 +83,8 @@ dev = [
     "flake8-bugbear >= 21.11.29",
     "flake8-docstrings >= 1.6.0",
     "ruff",
-    "dramatiq[rabbitmq]==1.16.0"
+    "dramatiq[rabbitmq]==1.16.0",
+    "rich==13.9.2",
 ]
 tests = ["pytest-cov==4.1.0", "pytest==7.4.1", "moto==4.2.2", "pytest-env ~= 0.6.2"]
 vis = ["matplotlib", "pydot"]