From 0204c2ed5c50e3a37aa6af3e38fae4cad3edd8c4 Mon Sep 17 00:00:00 2001 From: mathleur Date: Thu, 26 Sep 2024 15:25:28 +0200 Subject: [PATCH 1/2] add timing decorator function and simplify logs --- polytope/datacube/backends/fdb.py | 9 +++++---- .../datacube_merger/datacube_merger.py | 4 ++-- polytope/engine/hullslicer.py | 2 ++ polytope/polytope.py | 2 ++ polytope/utility/profiling.py | 12 ++++++++++++ 5 files changed, 23 insertions(+), 6 deletions(-) diff --git a/polytope/datacube/backends/fdb.py b/polytope/datacube/backends/fdb.py index cc427f566..9289d0f65 100644 --- a/polytope/datacube/backends/fdb.py +++ b/polytope/datacube/backends/fdb.py @@ -4,6 +4,7 @@ from itertools import product from ...utility.geometry import nearest_pt +from ...utility.profiling import timing_fn from .datacube import Datacube, TensorIndexTree @@ -14,7 +15,7 @@ def __init__(self, gj, config=None, axis_options=None, compressed_axes_options=[ super().__init__(axis_options, compressed_axes_options) - logging.info("Created an FDB datacube with options: " + str(axis_options)) + logging.debug("Created an FDB datacube with options: " + str(axis_options)) self.unwanted_path = {} self.axis_options = axis_options @@ -30,7 +31,7 @@ def __init__(self, gj, config=None, axis_options=None, compressed_axes_options=[ for axis_config in alternative_axes: self.fdb_coordinates[axis_config.axis_name] = axis_config.values - logging.info("Axes returned from GribJump are: " + str(self.fdb_coordinates)) + logging.debug("Axes returned from GribJump are: " + str(self.fdb_coordinates)) self.fdb_coordinates["values"] = [] for name, values in self.fdb_coordinates.items(): @@ -55,7 +56,7 @@ def __init__(self, gj, config=None, axis_options=None, compressed_axes_options=[ val = self._axes[name].type self._check_and_add_axes(options, name, val) - logging.info("Polytope created axes for %s", self._axes.keys()) + logging.debug("Polytope created axes for %s", self._axes.keys()) def check_branching_axes(self, request): polytopes = request.polytopes() @@ -77,10 +78,10 @@ def check_branching_axes(self, request): for axis_name in axes_to_remove: self._axes.pop(axis_name, None) + @timing_fn def get(self, requests: TensorIndexTree, context=None): if context is None: context = {} - requests.pprint() if len(requests.children) == 0: return requests fdb_requests = [] diff --git a/polytope/datacube/transformations/datacube_merger/datacube_merger.py b/polytope/datacube/transformations/datacube_merger/datacube_merger.py index 5b0516638..a132e7bbe 100644 --- a/polytope/datacube/transformations/datacube_merger/datacube_merger.py +++ b/polytope/datacube/transformations/datacube_merger/datacube_merger.py @@ -38,7 +38,7 @@ def merged_values(self, datacube): val_to_add = val_to_add.astype("datetime64[s]") merged_values.append(val_to_add) merged_values = np.array(merged_values) - logging.info( + logging.debug( f"Merged values {first_ax_vals} on axis {self.name} and \ values {second_ax_vals} on axis {second_ax_name} to values {merged_values}" ) @@ -64,7 +64,7 @@ def unmerge(self, merged_val): # TODO: maybe replacing like this is too specific to time/dates? first_val = str(first_val).replace("-", "") second_val = second_val.replace(":", "") - logging.info( + logging.debug( f"Unmerged value {merged_val} to values {first_val} on axis {self.name} \ and {second_val} on axis {self._second_axis}" ) diff --git a/polytope/engine/hullslicer.py b/polytope/engine/hullslicer.py index 8d3df84a2..25f056e42 100644 --- a/polytope/engine/hullslicer.py +++ b/polytope/engine/hullslicer.py @@ -12,6 +12,7 @@ from ..utility.combinatorics import argmax, argmin, group, tensor_product, unique from ..utility.exceptions import UnsliceableShapeError from ..utility.geometry import lerp +from ..utility.profiling import timing_fn from .engine import Engine @@ -204,6 +205,7 @@ def remove_compressed_axis_in_union(self, polytopes): if axis == self.compressed_axes[-1]: self.compressed_axes.remove(axis) + @timing_fn def extract(self, datacube: Datacube, polytopes: List[ConvexPolytope]): # Determine list of axes to compress self.find_compressed_axes(datacube, polytopes) diff --git a/polytope/polytope.py b/polytope/polytope.py index 29a03d631..dbe6446e1 100644 --- a/polytope/polytope.py +++ b/polytope/polytope.py @@ -4,6 +4,7 @@ from .options import PolytopeOptions from .shapes import ConvexPolytope from .utility.exceptions import AxisOverdefinedError +from .utility.profiling import timing_fn class Request: @@ -56,6 +57,7 @@ def slice(self, polytopes: List[ConvexPolytope]): """Low-level API which takes a polytope geometry object and uses it to slice the datacube""" return self.engine.extract(self.datacube, polytopes) + @timing_fn def retrieve(self, request: Request, method="standard", context=None): """Higher-level API which takes a request and uses it to slice the datacube""" if context is None: diff --git a/polytope/utility/profiling.py b/polytope/utility/profiling.py index 26eb48dce..a1e6ab611 100644 --- a/polytope/utility/profiling.py +++ b/polytope/utility/profiling.py @@ -1,4 +1,5 @@ import time +import logging class benchmark(object): @@ -12,3 +13,14 @@ def __exit__(self, ty, val, tb): end = time.perf_counter() print("%s : %0.7f seconds" % (self.name, end - self.start)) return False + + +def timing_fn(func): + def wrapper(*arg, **kw): + t1 = time.perf_counter() + res = func(*arg, **kw) + time_taken = time.perf_counter() - t1 + fn_name = func.__name__ + logging.debug("Time taken for %s is %s seconds", fn_name, time_taken) + return res + return wrapper From 9e39b2277c0a7e268aa4d4449b876de293148999 Mon Sep 17 00:00:00 2001 From: mathleur Date: Thu, 26 Sep 2024 15:26:24 +0200 Subject: [PATCH 2/2] isort and black --- polytope/utility/profiling.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/polytope/utility/profiling.py b/polytope/utility/profiling.py index a1e6ab611..af9414ddd 100644 --- a/polytope/utility/profiling.py +++ b/polytope/utility/profiling.py @@ -1,5 +1,5 @@ -import time import logging +import time class benchmark(object): @@ -23,4 +23,5 @@ def wrapper(*arg, **kw): fn_name = func.__name__ logging.debug("Time taken for %s is %s seconds", fn_name, time_taken) return res + return wrapper