better logging

Author: FedeClaudi

proj/__init__.py

@@ -1,9 +1,11 @@
 import pyinspect
+from rich.pretty import install
 
-pyinspect.install_traceback(all_locals=False)
+install()
+pyinspect.install_traceback()
 
 # Set up logging
-from proj.utils.logging import log
+# from proj.utils.logging import log
 
 # import stuff
 from proj.model.config import Config

proj/environment/manager.py

@@ -4,18 +4,17 @@
 import logging
 import json
 
-from rich.logging import RichHandler
-
 from fcutils.file_io.io import save_yaml
 
-
 from proj.utils.misc import timestamp
-from proj import paths, log
+from proj import paths
 from proj.animation.animate import animate_from_images
 from proj.plotting.results import plot_results
 from proj.utils.dropbox import DropBoxUtils, upload_folder
 from proj.utils.slack import send_slack_message
 
+from loguru import logger
+
 
 class Manager:
     def __init__(self, model, winstor=False):
@@ -58,19 +57,23 @@ def __init__(self, model, winstor=False):
 
     def _start_logging(self):
         filename = str(self.datafolder / f"{self.exp_name}.log")
-        fh = logging.FileHandler(filename)
-        fh.setFormatter(RichHandler())
-        log.addHandler(fh)
+        logger.add(filename)
+        logger.info("Saving data at: {self.datafolder}")
 
-        log.info(
-            f"[bold green] Saving data at: {self.datafolder}",
-            extra={"markup": True},
-        )
+        # fh = logging.FileHandler(filename)
+        # fh.setFormatter(RichHandler(rich_tracebacks=True))
+        # log.addHandler(fh)
+        # log.addHandler(RichHandler(rich_tracebacks=True))
+
+        # log.info(
+        #     f"[bold green] Saving data at: {self.datafolder}",
+        #     extra={"markup": True},
+        # )
 
     def _log_conf(self):
         # log config.py
         conf = json.dumps(self.model.config_dict(), sort_keys=True, indent=4)
-        log.info("Config parameters:\n" + conf, extra={"markup": True})
+        logger.info("Config parameters:\n" + conf, extra={"markup": True})
 
     def _save_results(self):
         # save config
@@ -126,7 +129,7 @@ def _save_video(self):
     def _upload_to_dropbox(self):
         dbx = DropBoxUtils()
         dpx_path = self.datafolder.name
-        log.info(
+        logger.info(
             f"Uploading data to dropbox at: {dpx_path}", extra={"markup": True}
         )
 
@@ -153,13 +156,13 @@ def conclude(self):
 
         # Upload results to dropbox
         if self.winstor:
-            log.info("Uploading to dropbox", extra={"markup": True})
+            logger.info("Uploading to dropbox", extra={"markup": True})
             try:
                 self._upload_to_dropbox()
             except Exception as e:
                 logging.error(f"Failed to upload to dropbox: {e}")
 
-            log.info("Sending slack message", extra={"markup": True})
+            logger.info("Sending slack message", extra={"markup": True})
             send_slack_message(
                 f"""
                 \n
@@ -170,10 +173,10 @@ def conclude(self):
                 """
             )
         else:
-            log.info("Did not upload to dropbox", extra={"markup": True})
+            logger.info("Did not upload to dropbox", extra={"markup": True})
 
     def failed(self):
-        log.info("Sending slack FAILED message", extra={"markup": True})
+        logger.info("Sending slack FAILED message", extra={"markup": True})
         if self.winstor:
             send_slack_message(
                 f"""

proj/environment/plotter.py

@@ -148,6 +148,7 @@ def _plot_control(self, keep_s=1.2):
 
         ax.set(ylabel="Forces", xlabel="step n")
         ax.legend()
+        ax.set(title="Control")
 
         # mark the times a change of traj idx happened
         # for v in self.moved_to_next:
@@ -206,18 +207,38 @@ def _plot_current_variables(self):
         )
 
         ax.legend()
+        ax.set(title="Speed")
         ax.set(ylabel="speed", xlabel="trajectory progression")
 
     def _plot_accelerations(self):
         ax = self.accel_ax
         ax.clear()
 
         ax.bar(
-            [0, 1],
-            [self.model.curr_dxdt.v_dot, self.model.curr_dxdt.omega_dot],
-            color=[colors["v"], colors["omega"]],
+            [0, 1, 2, 3],
+            [
+                self.model.curr_dxdt.v_dot,
+                self.model.curr_dxdt.omega_dot,
+                self.model.curr_wheel_state.nudot_left,
+                self.model.curr_wheel_state.nudot_right,
+            ],
+            color=[
+                colors["v"],
+                colors["omega"],
+                desaturate_color(colors["tau_l"]),
+                desaturate_color(colors["tau_r"]),
+            ],
+        )
+        ax.set(
+            xticklabels=[
+                "$\dot{v}$",
+                "$\dot{\omega}$",
+                "$\dot{\\nu_R}$",
+                "$\dot{\\nu_L}$",
+            ],
+            xticks=[0, 1, 2, 3],
         )
-        ax.set(xticklabels=["$\dot{v}$", "$\dot{\omega}$"], xticks=[0, 1])
+        ax.set(title="Acceleration")
 
     def _plot_cost(self, keep_s=1.2):
         keep_n = int(keep_s / self.model.dt)
@@ -237,6 +258,7 @@ def _plot_cost(self, keep_s=1.2):
                     x, label=k, lw=3, solid_capstyle="round", color=colors[k],
                 )
         ax.legend()
+        ax.set(title="Cost")
 
     def _plot_goal(self, goal):
         self.goal_ax.clear()
@@ -256,6 +278,7 @@ def _plot_goal(self, goal):
 
         self.goal_ax.legend()
         self.goal_ax.set(xticks=[])
+        self.goal_ax.set(title="Goal")
 
     def visualize_world_live(self, curr_goals, elapsed=None):
         ax = self.xy_ax

proj/environment/trajectories.py

@@ -15,7 +15,9 @@
 from fcutils.maths.filtering import line_smoother
 
 from proj.utils.misc import interpolate_nans
-from proj import log
+
+# from proj import log
+from loguru import logger
 
 
 def complete_given_xy(x, y, params, planning_params):
@@ -83,7 +85,7 @@ def compute_trajectory_stats(
     )
 
     # log stuff
-    logging.info(
+    logger.info(
         f"""
         Trajectory metadata 
 
@@ -100,19 +102,26 @@ def compute_trajectory_stats(
     print(table)
 
     if waypoint_density < 2 or waypoint_density > 3:
-        log.info(
-            f"[bold red]Waypoint density of {round(waypoint_density, 3)} out of range, it should be 2 < wp < 3!",
+        logger.info(
+            f"Waypoint density of {round(waypoint_density, 3)} out of range, it should be 2 < wp < 3!",
             extra={"markdown": True},
         )
+        print(
+            f"[bold red]Waypoint density of {round(waypoint_density, 3)} out of range, it should be 2 < wp < 3!"
+        )
 
     if perc_lookahead < 0.05:
-        log.info(
-            f"[bold red]Lookahead of {lookahead} is {perc_lookahead} of the # of waypoints, that might be too low. Values closer to 5% are advised.",
+        logger.info(
+            f"Lookahead of {lookahead} is {perc_lookahead} of the # of waypoints, that might be too low. Values closer to 5% are advised.",
             extra={"markdown": True},
         )
-
+        print(
+            f"[bold red]Lookahead of {lookahead} is {perc_lookahead} of the # of waypoints, that might be too low. Values closer to 5% are advised."
+        )
     if distance_travelled < min_dist_travelled * params["px_to_cm"]:
-        log.warning("Distance travelled below minimal requirement, erroring")
+        logger.warning(
+            "Distance travelled below minimal requirement, erroring"
+        )
         return None, None
 
     return trajectory, duration

proj/model/config.py

@@ -57,7 +57,7 @@ class Config:
     mouse_type = "realistic"
     model_type = "cart"
 
-    dt = 0.005
+    dt = 0.01
 
     # ------------------------------ Goal trajectory ----------------------------- #
 

proj/model/model.py

@@ -271,26 +271,27 @@ def get_wheels_dynamics(self):
             v,
             omega,
         ) = self.variables.values()
-
-        x_dot, y_dot, theta_dot = symbols("xdot, ydot, thetadot")
         nu_l_dot, nu_r_dot = symbols("nudot_L, nudot_R")
 
-        vels = Matrix([x_dot, y_dot, theta_dot])
+        # define vecs and matrices
+        vels = Matrix([v, omega])
         K = Matrix(
             [
                 [R / 2 * cos(theta), R / 2 * cos(theta)],
                 [R / 2 * sin(theta), R / 2 * sin(theta)],
-                [R / (2 * L), R / (2 * L)],
+                [R / (2 * L), -R / (2 * L)],
             ]
         )
 
+        Q = Matrix([[sin(theta), 0], [cos(theta), 0], [0, 1]])
+
         # In the model you can use the wheels accelerations
         # to get the x,y,theta velocity.
         # Here we do the inverse, given x,y,theta velocities
         # we get the wheel's accelerations
 
-        nu = K.pinv() * vels
-        args = [L, R, theta, x_dot, y_dot, theta_dot]
+        nu = K.pinv() * Q * vels
+        args = [L, R, theta, v, omega]
         self.calc_wheels_accels = lambdify(args, nu, modules="numpy")
 
     def step(self, u):
@@ -315,9 +316,8 @@ def step(self, u):
             variables["L"],
             variables["R"],
             variables["theta"],
-            self.curr_dxdt.x_dot,
-            self.curr_dxdt.y_dot,
-            self.curr_dxdt.theta_dot,
+            self.curr_x.v,
+            self.curr_x.omega,
         )
         self.curr_wheel_state = self._wheel_state(*w.ravel())
 

proj/run/runner.py

@@ -7,8 +7,8 @@
 import numpy as np
 from rich import print
 from rich.text import Text
-import logging
-import traceback
+
+from loguru import logger
 
 
 class SpeedColumn(TextColumn):
@@ -55,12 +55,11 @@ def run_experiment(
 
         :returns: the history of events as stored by model
     """
-    log = logging.getLogger("rich")
 
     # reset things
     trajectory = environment.reset()
     if trajectory is None:
-        log.info("Failed to get a valid trajectory")
+        logger.info("Failed to get a valid trajectory")
         environment.failed()
         return
 
@@ -102,27 +101,26 @@ def run_experiment(
 
                 # log status once a (simulation) second
                 if itern % int(1 / model.dt) == 0:
-                    log.info(
+                    logger.info(
                         f"Iteration {itern}/{n_steps}. Current cost: {environment.curr_cost}."
                     )
 
                 # Check if we're done
                 if environment.isdone(model.curr_x, trajectory):
-                    log.info("environment says we're DONE")
+                    logger.info("environment says we're DONE")
                     break
                 if environment.stop:
-                    log.info("environment says STOP")
+                    logger.info("environment says STOP")
                     break
 
             except Exception as e:
-                logging.error(
+                logger.exception(
                     f"Failed to take next step in simulation.\nError: {e}\n\n"
                 )
-                logging.error(traceback.print_exc())
                 environment.failed()
                 return
 
-    log.info(f"Terminated after {itern} iterations.")
+    logger.info(f"Terminated after {itern} iterations.")
 
     # save data and close stuff
     environment.conclude()

proj/utils/logging.py

@@ -1,23 +1,26 @@
 import logging
 from rich.logging import RichHandler
-from rich.console import Console
 
 # supress warnings
 import pandas as pd
 import warnings
 
+from loguru import logger
+
+
 warnings.simplefilter(action="ignore", category=pd.errors.PerformanceWarning)
 
 # Set up RICH logger
-logging.basicConfig(
-    level=logging.INFO,
-    format="%(message)s",
-    datefmt="[%X]",
-    handlers=[RichHandler(rich_tracebacks=True)],
+logger.configure(
+    handlers=[
+        {
+            "sink": RichHandler(rich_tracebacks=True, markup=True),
+            "format": "{message}",
+        }
+    ]
 )
-
-log = logging.getLogger("rich")
-logging_console = Console(record=True)
+logger.debug("This is a debug statement")
+logger.info("This is an info statement")
 
 
 # Disable logging some packages

run_allocentric.py

@@ -2,7 +2,7 @@
 
 import pyinspect
 
-pyinspect.install_traceback(all_locals=False)
+pyinspect.install_traceback()
 
 
 from proj import (