reslice clock time added into the log

httomo/data/dataset_store.py

@@ -117,7 +117,7 @@ def aux_data(self) -> AuxiliaryData:
     def write_block(self, block: DataSetBlock):
         if self._readonly:
             raise ValueError("Cannot write after creating a reader")
-        block.to_cpu()
+        block.to_cpu()  # TODO: possibly needs moving outside the block writing
         start = max(block.chunk_index_unpadded)
         if self._data is None:
             # if non-slice dims in block are different, update the shapes here
@@ -284,7 +284,19 @@ def __init__(
             self._slicing_dim = source.slicing_dim
             self._data = source_data
         else:
+            start = time.perf_counter()
             self._data = self._reslice(source.slicing_dim, slicing_dim, source_data)
+            end = time.perf_counter()
+            if slicing_dim == 1:
+                log_once(
+                    f"Slicing axis change (reslice) from projection to sinogram took {(end - start):.9f}s.",
+                    level=logging.INFO,
+                )
+            else:
+                log_once(
+                    f"Slicing axis change (reslice) from sinogram to projection took {(end - start):.9f}s.",
+                    level=logging.INFO,
+                )
             self._slicing_dim = slicing_dim
 
         self._padding = (0, 0) if padding is None else padding

httomo/runner/task_runner.py

@@ -145,7 +145,6 @@ def _execute_section(self, section: Section, section_index: int = 0):
         self._pass_min_block_length_to_intermediate_data_wrapper(section)
 
         splitter = BlockSplitter(self.source, section.max_slices)
-        start_source = time.perf_counter_ns()
         no_of_blocks = len(splitter)
 
         # Redirect tqdm progress bar output to /dev/null, and instead manually write block
@@ -156,6 +155,7 @@ def _execute_section(self, section: Section, section_index: int = 0):
             unit="block",
             ascii=True,
         )
+        start_source = time.perf_counter_ns()
         for idx, block in enumerate(progress):
             end_source = time.perf_counter_ns()
             if self.monitor is not None:
@@ -274,9 +274,9 @@ def _execute_method(
     ) -> DataSetBlock:
         start = time.perf_counter_ns()
         block = method.execute(block)
+        end = time.perf_counter_ns()
         if block.is_last_in_chunk:
             self.append_side_outputs(method.get_side_output())
-        end = time.perf_counter_ns()
         if self.monitor is not None:
             self.monitor.report_method_block(
                 method.method_name,

httomo/utils.py

@@ -59,6 +59,8 @@ def log_once(output: Any, level: int = logging.INFO) -> None:
                 logger.opt(colors=True).info("<red>{}</red>".format(output))
             elif "Advisory" in output:
                 logger.opt(colors=True).info("\033[43m{}\033[0m".format(output))
+            elif "reslice" in output:
+                logger.opt(colors=True).info("<blue>{}</blue>".format(output))
             else:
                 logger.info(output)