diff --git a/pytential/qbx/geometry.py b/pytential/qbx/geometry.py index f9cc10e07e0ea0ec84dbb545bcde644d10b547e0..8e219d72604a5ca5e3a5e3029abf659d54777069 100644 --- a/pytential/qbx/geometry.py +++ b/pytential/qbx/geometry.py @@ -32,6 +32,7 @@ from boxtree.tools import DeviceDataRecord import loopy as lp from loopy.version import MOST_RECENT_LANGUAGE_VERSION from cgen import Enum +from time import time from pytential.qbx.utils import TreeCodeContainerMixin @@ -677,7 +678,8 @@ class QBXFMMGeometryData(object): user_target_to_center = self.user_target_to_center() with cl.CommandQueue(self.cl_context) as queue: - logger.info("find global qbx centers: start") + logger.debug("find global qbx centers: start") + center_find_start_time = time() tgt_assoc_result = ( user_target_to_center.with_queue(queue)[self.ncenters:]) @@ -703,7 +705,14 @@ class QBXFMMGeometryData(object): ], queue=queue) - logger.info("find global qbx centers: done") + center_find_elapsed = time() - center_find_start_time + if center_find_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + + done_logger("find global qbx centers: done after %g seconds", + center_find_elapsed) if self.debug: logger.debug( @@ -764,7 +773,8 @@ class QBXFMMGeometryData(object): user_ttc = self.user_target_to_center() with cl.CommandQueue(self.cl_context) as queue: - logger.info("build center -> targets lookup table: start") + logger.debug("build center -> targets lookup table: start") + c2t_start_time = time() tree_ttc = cl.array.empty_like(user_ttc).with_queue(queue) tree_ttc[self.tree().sorted_target_ids] = user_ttc @@ -788,7 +798,13 @@ class QBXFMMGeometryData(object): filtered_tree_ttc, filtered_target_ids, self.ncenters, tree_ttc.dtype) - logger.info("build center -> targets lookup table: done") + c2t_elapsed = time() - c2t_start_time + if c2t_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + done_logger("build center -> targets lookup table: " + "done after %g seconds", c2t_elapsed) result = CenterToTargetList( starts=center_target_starts, @@ -807,7 +823,8 @@ class QBXFMMGeometryData(object): """ with cl.CommandQueue(self.cl_context) as queue: - logger.info("find non-qbx box target lists: start") + logger.debug("find non-qbx box target lists: start") + nonqbx_start_time = time() flags = (self.user_target_to_center().with_queue(queue) == target_state.NO_QBX_NEEDED) @@ -824,7 +841,13 @@ class QBXFMMGeometryData(object): plfilt = self.code_getter.particle_list_filter() result = plfilt.filter_target_lists_in_tree_order(queue, tree, flags) - logger.info("find non-qbx box target lists: done") + nonqbx_elapsed = time() - nonqbx_start_time + if nonqbx_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + done_logger("find non-qbx box target lists: done after %g seconds", + nonqbx_elapsed) return result.with_queue(None) diff --git a/pytential/qbx/target_assoc.py b/pytential/qbx/target_assoc.py index 7b9736ce4b6d34f70dcb411bfcba387ea2ec7889..8d85a5dcf6715182ada6918332303dc48d000b9c 100644 --- a/pytential/qbx/target_assoc.py +++ b/pytential/qbx/target_assoc.py @@ -39,6 +39,7 @@ from cgen import Enum from pytential.qbx.utils import ( QBX_TREE_C_PREAMBLE, QBX_TREE_MAKO_DEFS, TreeWranglerBase, TreeCodeContainerMixin) +from time import time unwrap_args = AreaQueryElementwiseTemplate.unwrap_args @@ -497,7 +498,8 @@ class TargetAssociationWrangler(TreeWranglerBase): wait_for=wait_for) wait_for = [evt] - logger.info("target association: marking targets close to panels") + logger.debug("target association: marking targets close to panels") + mark_start_time = time() tunnel_radius_by_source = lpot_source._close_target_tunnel_radius("nsources") @@ -527,7 +529,13 @@ class TargetAssociationWrangler(TreeWranglerBase): cl.wait_for_events([evt]) - logger.info("target association: done marking targets close to panels") + mark_elapsed = time() - mark_start_time + if mark_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + done_logger("target association: done marking targets close to panels " + "after %g seconds", mark_elapsed) return (found_target_close_to_panel == 1).all().get() @@ -582,7 +590,8 @@ class TargetAssociationWrangler(TreeWranglerBase): wait_for.extend(min_dist_to_center.events) - logger.info("target association: finding centers for targets") + logger.debug("target association: finding centers for targets") + center_find_start_time = time() evt = knl( *unwrap_args( @@ -613,8 +622,15 @@ class TargetAssociationWrangler(TreeWranglerBase): .format(ntargets_associated)) cl.wait_for_events([evt]) - logger.info("target association: done finding centers for targets") - return + + center_find_elapsed = time() - center_find_start_time + if center_find_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + + done_logger("target association: done finding centers for targets " + "after %g seconds", center_find_elapsed) def mark_panels_for_refinement(self, tree, peer_lists, lpot_source, target_status, refine_flags, debug, @@ -653,7 +669,8 @@ class TargetAssociationWrangler(TreeWranglerBase): wait_for=wait_for) wait_for = [evt] - logger.info("target association: marking panels for refinement") + logger.debug("target association: marking panels for refinement") + mark_start_time = time() evt = knl( *unwrap_args( @@ -684,7 +701,14 @@ class TargetAssociationWrangler(TreeWranglerBase): cl.wait_for_events([evt]) - logger.info("target association: done marking panels for refinement") + mark_elapsed = time() - mark_start_time + if mark_elapsed > 0.1: + done_logger = logger.info + else: + done_logger = logger.debug + + done_logger("target association: done marking panels for refinement " + "after %g seconds", mark_elapsed) return (found_panel_to_refine == 1).all().get()