diff --git a/source/blender/nodes/NOD_geometry_nodes_lazy_function.hh b/source/blender/nodes/NOD_geometry_nodes_lazy_function.hh index 1d767dd1c78..ee0f88f7ffe 100644 --- a/source/blender/nodes/NOD_geometry_nodes_lazy_function.hh +++ b/source/blender/nodes/NOD_geometry_nodes_lazy_function.hh @@ -502,6 +502,34 @@ class ScopedComputeContextTimer { } }; +/** + * Utility to measure the time that is spend in a specific node during geometry nodes evaluation. + */ +class ScopedNodeTimer { + private: + const lf::Context &context_; + const bNode &node_; + geo_eval_log::TimePoint start_; + + public: + ScopedNodeTimer(const lf::Context &context, const bNode &node) : context_(context), node_(node) + { + start_ = geo_eval_log::Clock::now(); + } + + ~ScopedNodeTimer() + { + const geo_eval_log::TimePoint end = geo_eval_log::Clock::now(); + auto &user_data = static_cast(*context_.user_data); + auto &local_user_data = static_cast(*context_.local_user_data); + if (geo_eval_log::GeoTreeLogger *tree_logger = local_user_data.try_get_tree_logger(user_data)) + { + tree_logger->node_execution_times.append(*tree_logger->allocator, + {node_.identifier, start_, end}); + } + } +}; + bool should_log_socket_values_for_context(const GeoNodesLFUserData &user_data, const ComputeContextHash hash); diff --git a/source/blender/nodes/intern/geometry_nodes_foreach_geometry_element_zone.cc b/source/blender/nodes/intern/geometry_nodes_foreach_geometry_element_zone.cc index 5031d569bf2..c5bce90e21f 100644 --- a/source/blender/nodes/intern/geometry_nodes_foreach_geometry_element_zone.cc +++ b/source/blender/nodes/intern/geometry_nodes_foreach_geometry_element_zone.cc @@ -324,6 +324,8 @@ class LazyFunctionForForeachGeometryElementZone : public LazyFunction { void execute_impl(lf::Params ¶ms, const lf::Context &context) const override { + const ScopedNodeTimer node_timer{context, output_bnode_}; + auto &user_data = *static_cast(context.user_data); auto &local_user_data = *static_cast(context.local_user_data); @@ -332,16 +334,6 @@ class LazyFunctionForForeachGeometryElementZone : public LazyFunction { auto &eval_storage = *static_cast(context.storage); geo_eval_log::GeoTreeLogger *tree_logger = local_user_data.try_get_tree_logger(user_data); - /* Measure execution time of the entire zone. */ - const geo_eval_log::TimePoint start_time = geo_eval_log::Clock::now(); - BLI_SCOPED_DEFER([&]() { - if (tree_logger) { - const geo_eval_log::TimePoint end_time = geo_eval_log::Clock::now(); - tree_logger->node_execution_times.append(*tree_logger->allocator, - {output_bnode_.identifier, start_time, end_time}); - } - }); - if (!eval_storage.graph_executor) { /* Create the execution graph in the first evaluation. */ this->initialize_execution_graph(params, eval_storage, node_storage); diff --git a/source/blender/nodes/intern/geometry_nodes_lazy_function.cc b/source/blender/nodes/intern/geometry_nodes_lazy_function.cc index 91aea5168a3..663bef17dea 100644 --- a/source/blender/nodes/intern/geometry_nodes_lazy_function.cc +++ b/source/blender/nodes/intern/geometry_nodes_lazy_function.cc @@ -196,6 +196,8 @@ class LazyFunctionForGeometryNode : public LazyFunction { void execute_impl(lf::Params ¶ms, const lf::Context &context) const override { + const ScopedNodeTimer node_timer{context, node_}; + GeoNodesLFUserData *user_data = dynamic_cast(context.user_data); BLI_assert(user_data != nullptr); const auto &local_user_data = *static_cast(context.local_user_data); @@ -254,15 +256,7 @@ class LazyFunctionForGeometryNode : public LazyFunction { own_lf_graph_info_.mapping.lf_input_index_for_reference_set_for_output, get_anonymous_attribute_name}; - geo_eval_log::TimePoint start_time = geo_eval_log::Clock::now(); node_.typeinfo->geometry_node_execute(geo_params); - geo_eval_log::TimePoint end_time = geo_eval_log::Clock::now(); - - if (geo_eval_log::GeoTreeLogger *tree_logger = local_user_data.try_get_tree_logger(*user_data)) - { - tree_logger->node_execution_times.append(*tree_logger->allocator, - {node_.identifier, start_time, end_time}); - } } std::string input_name(const int index) const override @@ -1134,6 +1128,7 @@ class LazyFunctionForGroupNode : public LazyFunction { void execute_impl(lf::Params ¶ms, const lf::Context &context) const override { + const ScopedNodeTimer node_timer{context, group_node_}; GeoNodesLFUserData *user_data = dynamic_cast(context.user_data); BLI_assert(user_data != nullptr); @@ -1470,6 +1465,7 @@ class LazyFunctionForSimulationZone : public LazyFunction { void execute_impl(lf::Params ¶ms, const lf::Context &context) const override { + ScopedNodeTimer node_timer{context, sim_output_bnode_}; GeoNodesLFUserData &user_data = *static_cast(context.user_data); bke::SimulationZoneComputeContext compute_context{user_data.compute_context, @@ -1482,8 +1478,6 @@ class LazyFunctionForSimulationZone : public LazyFunction { GeoNodesLFLocalUserData zone_local_user_data{zone_user_data}; lf::Context zone_context{context.storage, &zone_user_data, &zone_local_user_data}; - - ScopedComputeContextTimer timer(zone_context); fn_.execute(params, zone_context); } diff --git a/source/blender/nodes/intern/geometry_nodes_log.cc b/source/blender/nodes/intern/geometry_nodes_log.cc index 300479c26d2..013bb88fa98 100644 --- a/source/blender/nodes/intern/geometry_nodes_log.cc +++ b/source/blender/nodes/intern/geometry_nodes_log.cc @@ -351,18 +351,6 @@ void GeoTreeLog::ensure_execution_times() } this->execution_time += tree_logger->execution_time; } - for (const ComputeContextHash &child_hash : children_hashes_) { - GeoTreeLog &child_log = modifier_log_->get_tree_log(child_hash); - if (child_log.tree_loggers_.is_empty()) { - continue; - } - child_log.ensure_execution_times(); - const std::optional &parent_node_id = child_log.tree_loggers_[0]->parent_node_id; - if (parent_node_id.has_value()) { - this->nodes.lookup_or_add_default(*parent_node_id).execution_time += - child_log.execution_time; - } - } reduced_execution_times_ = true; } diff --git a/source/blender/nodes/intern/geometry_nodes_repeat_zone.cc b/source/blender/nodes/intern/geometry_nodes_repeat_zone.cc index 2a38fc1ce15..28979ba906d 100644 --- a/source/blender/nodes/intern/geometry_nodes_repeat_zone.cc +++ b/source/blender/nodes/intern/geometry_nodes_repeat_zone.cc @@ -54,8 +54,6 @@ class RepeatBodyNodeExecuteWrapper : public lf::GraphExecutorNodeExecuteWrapper GeoNodesLFLocalUserData body_local_user_data{body_user_data}; lf::Context body_context{context.storage, &body_user_data, &body_local_user_data}; - - ScopedComputeContextTimer timer(body_context); fn.execute(params, body_context); } }; @@ -148,6 +146,8 @@ class LazyFunctionForRepeatZone : public LazyFunction { void execute_impl(lf::Params ¶ms, const lf::Context &context) const override { + const ScopedNodeTimer node_timer{context, repeat_output_bnode_}; + auto &user_data = *static_cast(context.user_data); auto &local_user_data = *static_cast(context.local_user_data);