Merge pull request #461 from hakonanes/add-indexing-speed-print

Print indexing and refinement speed

CHANGELOG.rst

@@ -12,7 +12,7 @@ best to adhere to `Semantic Versioning <https://semver.org/spec/v2.0.0.html>`_.
 Contributors to each release are listed in alphabetical order by first name. List
 entries are sorted in descending chronological order.
 
-0.5.3 (2021-11-01)
+0.5.3 (2021-11-02)
 ==================
 
 Contributors
@@ -22,8 +22,10 @@ Contributors
 
 Added
 -----
-- Restricted newest version of h5py<=3.4 due to issue with IO function imported from
-  HyperSpy. (`#455 <https://github.com/pyxem/kikuchipy/pull/455>`_)
+- Printing of speed (patterns per second) of dictionary indexing and refinement.
+  (`#461 <https://github.com/pyxem/kikuchipy/pull/461>`_)
+- Restricted newest version of hyperspy<=1.6.5 due to incompatibility with h5py>=3.5.
+  (`#461 <https://github.com/pyxem/kikuchipy/pull/461>`_)
 
 Fixed
 -----

kikuchipy/indexing/_dictionary_indexing.py

@@ -20,6 +20,7 @@
 dictionary of simulated patterns with known orientations.
 """
 
+from time import sleep, time
 from typing import ClassVar, Tuple, Union
 
 import dask.array as da
@@ -79,6 +80,7 @@ def _dictionary_indexing(
         )
     )
 
+    time_start = time()
     if dictionary_size == n_per_iteration:
         simulation_indices, scores = _match_chunk(
             experimental,
@@ -89,11 +91,11 @@ def _dictionary_indexing(
         with ProgressBar():
             simulation_indices, scores = da.compute(simulation_indices, scores)
     else:
-        simulation_indices = np.zeros((n_experimental, keep_n), dtype=np.int32)
-        scores = np.full((n_experimental, keep_n), -metric.sign, dtype=metric.dtype)
-
         negative_sign = -metric.sign
 
+        simulation_indices = np.zeros((n_experimental, keep_n), dtype=np.int32)
+        scores = np.full((n_experimental, keep_n), negative_sign, dtype=metric.dtype)
+
         lazy_dictionary = isinstance(dictionary, da.Array)
 
         chunk_starts = np.cumsum([0] + [n_per_iteration] * (n_iterations - 1))
@@ -124,6 +126,19 @@ def _dictionary_indexing(
                 all_simulation_indices, best_indices, axis=1
             )
 
+    total_time = time() - time_start
+    patterns_per_second = int(np.floor(n_experimental / total_time))
+    comparisons_per_second = int(
+        np.floor(n_experimental * dictionary_size / total_time)
+    )
+    # Without this pause, a part of the red tqdm progressbar background
+    # is displayed below this print
+    sleep(0.1)
+    print(
+        f"\tIndexing speed: {patterns_per_second} patterns/s, "
+        f"{comparisons_per_second} comparisons/s"
+    )
+
     coordinate_arrays, _ = create_coordinate_arrays(
         shape=experimental_nav_shape, step_sizes=step_sizes
     )

kikuchipy/indexing/_refinement/_refinement.py

@@ -23,6 +23,7 @@
 
 import gc
 import sys
+from time import time
 from typing import Callable, Optional, Tuple, Union
 
 import dask
@@ -637,7 +638,11 @@ def compute_refine_orientation_results(results: list, xmap: CrystalMap, master_p
     n_patterns = len(results)
     with ProgressBar():
         print(f"Refining {n_patterns} orientation(s):", file=sys.stdout)
+        time_start = time()
         computed_results = dask.compute(*results)
+        total_time = time() - time_start
+        patterns_per_second = int(np.floor(n_patterns / total_time))
+        print(f"Refinement speed: {patterns_per_second} patterns/s")
         # (n, score, phi1, Phi, phi2)
         computed_results = np.array(computed_results)
         xmap_refined = CrystalMap(
@@ -680,7 +685,11 @@ def compute_refine_projection_center_results(results: list, detector, xmap: Crys
     nav_shape = xmap.shape
     with ProgressBar():
         print(f"Refining {n_patterns} projection center(s):", file=sys.stdout)
+        time_start = time()
         computed_results = dask.compute(*results)
+        total_time = time() - time_start
+        patterns_per_second = int(np.floor(n_patterns / total_time))
+        print(f"Refinement speed: {patterns_per_second} patterns/s")
         # (n, score, PCx, PCy, PCz)
         computed_results = np.array(computed_results)
         new_detector = detector.deepcopy()
@@ -728,7 +737,11 @@ def compute_refine_orientation_projection_center_results(
             f"Refining {n_patterns} orientation(s) and projection center(s):",
             file=sys.stdout,
         )
+        time_start = time()
         computed_results = dask.compute(*results)
+        total_time = time() - time_start
+        patterns_per_second = int(np.floor(n_patterns / total_time))
+        print(f"Refinement speed: {patterns_per_second} patterns/s")
         computed_results = np.array(computed_results)
         # (n, score, phi1, Phi, phi2, PCx, PCy, PCz)
         xmap_refined = CrystalMap(

setup.py

@@ -122,9 +122,8 @@
     install_requires=[
         "dask[array]        >= 2021.8.1",
         "diffsims           >= 0.4",
-        # TODO: Bump to 1.6.5 and unpin h5py <= 3.4 when 1.6.5 is out
-        "hyperspy           >= 1.6.4",
-        "h5py               >= 2.10, <= 3.4",
+        "hyperspy           >= 1.6.5",
+        "h5py               >= 2.10",
         "matplotlib         >= 3.3",
         "numpy              >= 1.19",
         "numba              >= 0.48",