diff --git a/bt5/erp5_base/MixinTemplateItem/portal_components/mixin.erp5.BuilderMixin.py b/bt5/erp5_base/MixinTemplateItem/portal_components/mixin.erp5.BuilderMixin.py index d3a9fa140f15733a973e5cc06c3c0a3f31ed4ae1..c7d1b175c556abff32454dc517dadef5a93115d4 100644 --- a/bt5/erp5_base/MixinTemplateItem/portal_components/mixin.erp5.BuilderMixin.py +++ b/bt5/erp5_base/MixinTemplateItem/portal_components/mixin.erp5.BuilderMixin.py @@ -110,6 +110,10 @@ class BuilderMixin(XMLObject, Amount, Predicate): restrict selection to a given root Applied Rule caused by a single Order or to Simulation Movements related to a limited set of existing """ + import datetime + import logging + logger = logging.getLogger("%s(%s)" % (__name__, self.getRelativeUrl())) + total_start = datetime.datetime.now() # Parameter initialization if delivery_relative_url_list is None: delivery_relative_url_list = [] @@ -133,19 +137,35 @@ class BuilderMixin(XMLObject, Amount, Predicate): kw['causality_uid'] = [link_value.getUid() for link_value in business_link_value_list] if applied_rule_uid is not None: kw['applied_rule_uid'] = applied_rule_uid + + start = datetime.datetime.now() movement_list = self.searchMovementList(**kw) + logger.info( + 'Found %s movements in %s', len(movement_list), datetime.datetime.now() - start ) if not movement_list: + logger.info('No movement found') return [] + # Collect + start = datetime.datetime.now() root_group_node = self.collectMovement(movement_list, merge_delivery=merge_delivery) + logger.info('Collected in %s', datetime.datetime.now() - start ) + # Build + start = datetime.datetime.now() delivery_list = self.buildDeliveryList( root_group_node, delivery_relative_url_list=delivery_relative_url_list, movement_list=movement_list, activate_kw=activate_kw, merge_delivery=merge_delivery, **kw) + logger.info('Built %s deliveries in %s', len(delivery_list), datetime.datetime.now() - start ) + # Call a script after building + start = datetime.datetime.now() self.callAfterBuildingScript(delivery_list, movement_list, **kw) + logger.info('callAfterBuildingScript in %s', datetime.datetime.now() - start ) + + logger.info('Total build() time for %s deliveries in %s', len(delivery_list), datetime.datetime.now() - total_start ) return delivery_list def getRelatedBusinessLinkValueList(self):