Repository: MathisFederico/LearnRL (language: python)

Issue:
Display error
`metrics = [
        "exploration~exp.last",
        ("reward~rwd", {"episode": "sum"}),
        "dt_step~",
        "loss"
    ]`

display : 
![image](https://user-images.githubusercontent.com/67725350/111354994-330b0800-8687-11eb-9f21-f54fb96b301c.png)



Discussion / hints:
dt_step should be at the end for now, I'll add a fix to strange logger behaviors soon

Fix patch:
diff --git a/learnrl/callbacks/logger.py b/learnrl/callbacks/logger.py
index 0f2f838..725a8b3 100644
--- a/learnrl/callbacks/logger.py
+++ b/learnrl/callbacks/logger.py
@@ -50,11 +50,14 @@ def __init__(self,
         """
 
         if metrics is None:
-            metrics = [('reward', {'steps_cycles': 'sum', 'episode': 'sum'})]
+            metrics = [
+                ('reward', {'steps_cycles': 'sum', 'episode': 'sum'}),
+                'dt_step~'
+            ]
         if detailed_step_metrics is None:
             detailed_step_metrics = ['observation', 'action', 'next_observation']
         if episode_only_metrics is None:
-            episode_only_metrics = ('dt_episode~')
+            episode_only_metrics = ['dt_episode~']
 
         super().__init__(
             metrics=metrics,
@@ -62,12 +65,13 @@ def __init__(self,
             episode_only_metrics=episode_only_metrics,
         )
 
-        self._bar_lenght = 100
-        self._number_window = 9
         self.titles_on_top = titles_on_top
-        self.step_start_cycle = None
         self.verbose = None
-        self.n_digits_episodes = None
+
+        self._bar_lenght = 100
+        self._number_window = 9
+        self._number_window_time = 5
+        self._n_digits_episodes = None
 
     def on_step_begin(self, step, logs=None):
         super().on_step_begin(step, logs=logs)
@@ -96,8 +100,6 @@ def on_step_end(self, step, logs=None):
     def on_steps_cycle_begin(self, step, logs=None):
         super().on_steps_cycle_begin(step, logs=logs)
 
-        if self.verbose == 3:
-            self.step_start_cycle = step
         if self.verbose == 4 and self.titles_on_top:
             step_text = self._get_step_text(0)
             self._print_titles(self.step_metrics, offset=' ' * len(step_text) + ' |', end='\n')
@@ -193,7 +195,7 @@ def on_episodes_cycle_end(self, episode, logs=None):
 
     def on_run_begin(self, logs=None):
         super().on_run_begin(logs=logs)
-        self.n_digits_episodes = int(np.log10(self.params['episodes'])) + 1
+        self._n_digits_episodes = int(np.log10(self.params['episodes'])) + 1
         self.verbose = self.params['verbose']
 
         if self.verbose == 5:
@@ -253,10 +255,15 @@ def _print_titles(self, metric_list:MetricList, prefix='', offset='', end=''):
         """ Print the titles of the metric list """
         print(prefix, end=offset)
         for metric in metric_list:
-            if not metric.name.startswith('dt'):
-                surname = metric.surname.capitalize()[:self._number_window]
-                display_name = self._text_in_middle(' ', surname, self._number_window+2)
-                print(display_name, end='|')
+            if not metric.name.startswith('dt_'):
+                capitalized_surname = metric.surname.capitalize()[0] + metric.surname[1:]
+                surname = capitalized_surname[:self._number_window]
+                title_lenght = self._number_window+2
+            else:
+                surname = metric.name[3:].capitalize() + ' time'
+                title_lenght = self._number_window_time + 9
+            display_name = self._text_in_middle(' ', surname, lenght=title_lenght)
+            print(display_name, end='|')
         print(end=end)
 
     def _print_bar(self, line, text=None, **kwargs):
@@ -275,7 +282,7 @@ def _text_in_middle(line, text, lenght):
     def _get_episode_text(self, episode):
         """ Get the display text for an episode """
         text = f"{episode+1}"
-        text = " " * (self.n_digits_episodes - len(text)) + text
+        text = " " * (self._n_digits_episodes - len(text)) + text
         text += f"/{self.params['episodes']}"
         return text
 
@@ -289,14 +296,15 @@ def _get_step_text(step, step_end=None, pad=True):
             text += ' ' * (13 - len(text))
         return text
 
-    @staticmethod
-    def _get_time_text(elapsed_time, unit):
+    def _get_time_text(self, elapsed_time, unit):
         """ Get the display text for a time mesurment """
-        if unit == 'episode':
-            unit = 'eps'
+        unit = unit[:4]
+        if isinstance(elapsed_time, str):
+            return elapsed_time
         if elapsed_time < 1e-9:
-            return '< 1ns      '
-        if elapsed_time < 1e-6:
+            time_display = '<1'
+            time_unit = 'ns'
+        elif elapsed_time < 1e-6:
             time_display = f'{elapsed_time/1e-9:.01f}'
             time_unit = 'ns'
         elif elapsed_time < 1e-3:
@@ -309,5 +317,5 @@ def _get_time_text(elapsed_time, unit):
             time_display = f'{elapsed_time:.01f}'
             time_unit = 's '
 
-        margin = (5 - len(time_display)) * ' '
+        margin = (self._number_window_time - len(time_display)) * ' '
         return margin + f'{time_display}{time_unit}/{unit}'
diff --git a/learnrl/callbacks/logging_callback.py b/learnrl/callbacks/logging_callback.py
index e9dd884..96ef6ef 100644
--- a/learnrl/callbacks/logging_callback.py
+++ b/learnrl/callbacks/logging_callback.py
@@ -79,12 +79,10 @@ def __init__(self,
         self.episode_only_metrics = MetricList(episode_only_metrics)
 
         metric_lists = self._extract_lists(metrics)
-
-        step_metrics, steps_cycle_metrics, episode_metrics, episodes_cycle_metrics = metric_lists
-        self.step_metrics = MetricList(step_metrics)
-        self.steps_cycle_metrics = MetricList(steps_cycle_metrics)
-        self.episode_metrics = MetricList(episode_metrics)
-        self.episodes_cycle_metrics = MetricList(episodes_cycle_metrics)
+        self.step_metrics = MetricList(metric_lists[0])
+        self.steps_cycle_metrics = MetricList(metric_lists[1])
+        self.episode_metrics = MetricList(metric_lists[2])
+        self.episodes_cycle_metrics = MetricList(metric_lists[3])
 
         self.n_agents = None
 
diff --git a/learnrl/playground.py b/learnrl/playground.py
index 1a22dbd..9836988 100644
--- a/learnrl/playground.py
+++ b/learnrl/playground.py
@@ -227,16 +227,13 @@ def _run_step(self,
             agent_logs = agent.learn()
             logs.update({f'agent_{agent_id}': agent_logs})
 
-        # Adds step informations to logs
-        logs.update({'agent_id':agent_id, 'observation':observation})
-
         # Ask action to agent
         action = agent.act(observation, greedy=not learn)
+
         # Perform environment step
         next_observation, reward, done, info = self.env.step(action)
-        logs.update(info)
 
-        # Compact experience
+        # Adds step informations to logs
         experience = {
             'observation': observation,
             'action': action,
@@ -245,6 +242,8 @@ def _run_step(self,
             'next_observation': next_observation,
             'info': info
         }
+        logs.update({'agent_id':agent_id})
+        logs.update(experience)
 
         # Use Handlers
         self._call_handlers(reward, done, experience, reward_handler, done_handler, logs)
@@ -264,9 +263,6 @@ def _run_step(self,
         if done and render:
             self.env.render(render_mode)
 
-        # Add experience to logs
-        logs.update(experience)
-
         return next_observation, done
 
     def run(self,


Test patch:
diff --git a/tests/unit/test_playground.py b/tests/unit/test_playground.py
index 0283b80..f628455 100644
--- a/tests/unit/test_playground.py
+++ b/tests/unit/test_playground.py
@@ -497,6 +497,7 @@ def setup_playground(self, mocker):
         self.observation = 'observation'
         self.next_observation = 'next_observation'
         self.reward = 1.2
+        self.handled_reward = 1.7
         self.done = False
         self.info = {'env_info': 'env_info'}
 
@@ -517,7 +518,12 @@ def setup_playground(self, mocker):
         self.agent_id = 0
         mocker.patch('learnrl.playground.Playground._get_next_agent',
             return_value=(self.agents[self.agent_id], self.agent_id))
-        mocker.patch('learnrl.playground.Playground._call_handlers')
+
+        def handler_mocker(cls, reward, done, experience, reward_handler, done_handler, logs):
+            experience['reward'] = self.handled_reward
+            logs['handled_reward'] = self.handled_reward
+
+        mocker.patch('learnrl.playground.Playground._call_handlers', handler_mocker)
         self.playground = Playground(self.env, self.agents)
 
         self.previous = [
@@ -538,8 +544,8 @@ def test_run_step(self):
         check.equal(observation, self.next_observation)
         check.equal(done, self.done)
 
-        for log_name in ['reward', 'observation', 'next_observation',
-                            'info', 'done', 'agent_id', 'action']:
+        for log_name in ['reward', 'handled_reward', 'observation',
+                            'next_observation', 'info', 'done', 'agent_id', 'action']:
             expected = getattr(self, log_name)
             check.equal(logs[log_name], expected)