Changed per-pipeline timings to store as a float (#4160)

docs/source/release_notes.rst

@@ -4,6 +4,7 @@ Release Notes
     * Enhancements
     * Fixes
     * Changes
+        * Changed per-pipeline timings to store as a float :pr:`4160`
     * Documentation Changes
     * Testing Changes
 

evalml/automl/automl_search.py

@@ -67,7 +67,6 @@
     log_batch_times,
     log_subtitle,
     log_title,
-    time_elapsed,
 )
 
 
@@ -1126,8 +1125,8 @@ def search(self, interactive_plot=True):
                             cached_data,
                             job_log,
                         )
-                        pipeline_times[pipeline.name] = time_elapsed(
-                            start_pipeline_time,
+                        pipeline_times[pipeline.name] = (
+                            time.time() - start_pipeline_time
                         )
                         new_pipeline_ids.append(pipeline_id)
                         computations[current_computation_index] = (computation, True)
@@ -1163,12 +1162,11 @@ def search(self, interactive_plot=True):
                     f"All pipelines in the current AutoML batch produced a score of np.nan on the primary objective {self.objective}. Exception(s) raised: {error_msgs}. Check the 'errors' attribute of the AutoMLSearch object for a full breakdown of errors and tracebacks.",
                 )
             if len(pipeline_times) > 0:
-                pipeline_times["Total time of batch"] = time_elapsed(start_batch_time)
+                pipeline_times["Total time of batch"] = time.time() - start_batch_time
                 batch_times[self._get_batch_number()] = pipeline_times
 
         self.search_duration = time.time() - self.progress.start_time
-        elapsed_time = time_elapsed(self.progress.start_time)
-        desc = f"\nSearch finished after {elapsed_time}"
+        desc = f"\nSearch finished after {self.search_duration:.2f} seconds"
         desc = desc.ljust(self._MAX_NAME_LEN)
         self.logger.info(desc)
 

evalml/tests/automl_tests/test_automl.py

@@ -256,9 +256,9 @@ def test_search_batch_times(caplog, X_y_binary, AutoMLTestEnv):
     assert isinstance(list(batch_times.keys())[0], int)
     assert isinstance(batch_times[1], dict)
     assert isinstance(list(batch_times[1].keys())[0], str)
-    assert isinstance(batch_times[1]["Total time of batch"], str)
-    assert isinstance(batch_times[2]["Total time of batch"], str)
-    assert isinstance(batch_times[3]["Total time of batch"], str)
+    assert isinstance(batch_times[1]["Total time of batch"], float)
+    assert isinstance(batch_times[2]["Total time of batch"], float)
+    assert isinstance(batch_times[3]["Total time of batch"], float)
 
     assert len(batch_times) == 3
     assert len(batch_times[1]) == 2

evalml/tests/utils_tests/test_logger.py

@@ -75,16 +75,13 @@ def test_logger_critical(caplog, logger_env_cleanup):
 
 def test_logger_batch_times(caplog, logger_env_cleanup):
     logger = get_logger(TEST_LOGGER_NAME)
-    batch_times = {"1": {"test": "00:01", "tset": "10:00"}, "2": {"pipe": "00:02"}}
+    batch_times = {"1": {"test": 1.2345, "tset": 9.8}, "2": {"pipe": 2}}
     log_batch_times(logger, batch_times)
     assert "Batch 1 time stats" in caplog.text
-    assert "test:" in caplog.text
-    assert "00:01" in caplog.text
-    assert "tset" in caplog.text
-    assert "10:00" in caplog.text
+    assert "test: 1.23 seconds" in caplog.text
+    assert "tset: 9.80 seconds" in caplog.text
     assert "Batch 2 time stats" in caplog.text
-    assert "pipe" in caplog.text
-    assert "00:02" in caplog.text
+    assert "pipe: 2.00 seconds" in caplog.text
 
 
 @pytest.mark.parametrize(

evalml/utils/logger.py

@@ -70,6 +70,9 @@ def log_batch_times(logger, batch_times):
         log_subtitle(logger, subtitle)
         for pipeline_name in batch_times[batch_number]:
             logger.info(
-                "\n" + pipeline_name + ": " + batch_times[batch_number][pipeline_name],
+                "\n"
+                + pipeline_name
+                + ": "
+                + f"{batch_times[batch_number][pipeline_name]:.2f} seconds",
             )
         logger.info("")