diff options
| -rw-r--r-- | release/scripts/startup/bl_ui/space_node.py | 4 | ||||
| -rw-r--r-- | source/blender/editors/space_node/drawnode.cc | 7 | ||||
| -rw-r--r-- | source/blender/editors/space_node/node_draw.cc | 235 | ||||
| -rw-r--r-- | source/blender/editors/space_node/node_intern.hh | 1 | ||||
| -rw-r--r-- | source/blender/makesdna/DNA_space_types.h | 1 | ||||
| -rw-r--r-- | source/blender/makesrna/intern/rna_space.c | 6 | ||||
| -rw-r--r-- | source/blender/modifiers/intern/MOD_nodes_evaluator.cc | 8 | ||||
| -rw-r--r-- | source/blender/nodes/NOD_geometry_nodes_eval_log.hh | 16 | ||||
| -rw-r--r-- | source/blender/nodes/intern/geometry_nodes_eval_log.cc | 13 |
9 files changed, 289 insertions, 2 deletions
diff --git a/release/scripts/startup/bl_ui/space_node.py b/release/scripts/startup/bl_ui/space_node.py index 2b3f0cfbf7c..afbd7e61aaa 100644 --- a/release/scripts/startup/bl_ui/space_node.py +++ b/release/scripts/startup/bl_ui/space_node.py @@ -721,6 +721,10 @@ class NODE_PT_overlay(Panel): col.prop(snode, "show_annotation", text="Annotations") + if snode.tree_type == 'GeometryNodeTree': + col.separator() + col.prop(overlay, "show_timing", text="Timings") + class NODE_UL_interface_sockets(bpy.types.UIList): def draw_item(self, context, layout, _data, item, icon, _active_data, _active_propname, _index): diff --git a/source/blender/editors/space_node/drawnode.cc b/source/blender/editors/space_node/drawnode.cc index cf79893a8cb..97fa93ab0bc 100644 --- a/source/blender/editors/space_node/drawnode.cc +++ b/source/blender/editors/space_node/drawnode.cc @@ -337,8 +337,9 @@ static void node_draw_frame_prepare(const bContext *UNUSED(C), bNodeTree *ntree, node->totr = rect; } -static void node_draw_frame_label(bNodeTree *ntree, bNode *node, const float aspect) +static void node_draw_frame_label(bNodeTree *ntree, bNode *node, SpaceNode *snode) { + const float aspect = snode->runtime->aspect; /* XXX font id is crap design */ const int fontid = UI_style_get()->widgetlabel.uifont_id; NodeFrame *data = (NodeFrame *)node->storage; @@ -468,7 +469,9 @@ static void node_draw_frame(const bContext *C, } /* label and text */ - node_draw_frame_label(ntree, node, snode->runtime->aspect); + node_draw_frame_label(ntree, node, snode); + + node_draw_extra_info_panel(snode, node); UI_block_end(C, node->block); UI_block_draw(C, node->block); diff --git a/source/blender/editors/space_node/node_draw.cc b/source/blender/editors/space_node/node_draw.cc index f9a9e491403..1aa6ec4e56c 100644 --- a/source/blender/editors/space_node/node_draw.cc +++ b/source/blender/editors/space_node/node_draw.cc @@ -87,6 +87,8 @@ #include "node_intern.hh" /* own include */ +#include <iomanip> + #ifdef WITH_COMPOSITOR # include "COM_compositor.h" #endif @@ -1577,6 +1579,237 @@ static void node_add_error_message_button( UI_block_emboss_set(node.block, UI_EMBOSS); } +static void get_exec_time_other_nodes(const bNode *node, + const SpaceNode *snode, + std::chrono::microseconds &exec_time, + int &node_count) +{ + if (node->type == NODE_GROUP) { + const geo_log::TreeLog *root_tree_log = geo_log::ModifierLog::find_tree_by_node_editor_context( + *snode); + if (root_tree_log == nullptr) { + return; + } + const geo_log::TreeLog *tree_log = root_tree_log->lookup_child_log(node->name); + if (tree_log == nullptr) { + return; + } + tree_log->foreach_node_log([&](const geo_log::NodeLog &node_log) { + exec_time += node_log.execution_time(); + node_count++; + }); + } + else { + const geo_log::NodeLog *node_log = geo_log::ModifierLog::find_node_by_node_editor_context( + *snode, *node); + if (node_log) { + exec_time += node_log->execution_time(); + node_count++; + } + } +} + +static std::chrono::microseconds node_get_execution_time(const bNodeTree *ntree, + const bNode *node, + const SpaceNode *snode, + int &node_count) +{ + std::chrono::microseconds exec_time = std::chrono::microseconds::zero(); + if (node->type == NODE_GROUP_OUTPUT) { + const geo_log::TreeLog *tree_log = geo_log::ModifierLog::find_tree_by_node_editor_context( + *snode); + + if (tree_log == nullptr) { + return exec_time; + } + tree_log->foreach_node_log([&](const geo_log::NodeLog &node_log) { + exec_time += node_log.execution_time(); + node_count++; + }); + } + else if (node->type == NODE_FRAME) { + /* Could be cached in the future if this recursive code turns out to be slow. */ + LISTBASE_FOREACH (bNode *, tnode, &ntree->nodes) { + if (tnode->parent != node) { + continue; + } + + if (tnode->type == NODE_FRAME) { + exec_time += node_get_execution_time(ntree, tnode, snode, node_count); + } + else { + get_exec_time_other_nodes(tnode, snode, exec_time, node_count); + } + } + } + else { + get_exec_time_other_nodes(node, snode, exec_time, node_count); + } + return exec_time; +} + +static std::string node_get_execution_time_label(const SpaceNode *snode, const bNode *node) +{ + int node_count = 0; + std::chrono::microseconds exec_time = node_get_execution_time( + snode->nodetree, node, snode, node_count); + + if (node_count == 0) { + return std::string(""); + } + + uint64_t exec_time_us = exec_time.count(); + + /* Don't show time if execution time is 0 microseconds. */ + if (exec_time_us == 0) { + return std::string("-"); + } + else if (exec_time_us < 100) { + return std::string("< 0.1 ms"); + } + else { + short precision = 0; + /* Show decimal if value is below 1ms */ + if (exec_time_us < 1000) { + precision = 2; + } + else if (exec_time_us < 10000) { + precision = 1; + } + + std::stringstream stream; + stream << std::fixed << std::setprecision(precision) << (exec_time_us / 1000.0f); + return std::string(stream.str() + " ms"); + } + return std::string(""); +} + +struct NodeExtraInfoRow { + std::string text; + const char *tooltip; + int icon; +}; + +static Vector<NodeExtraInfoRow> node_get_extra_info(const SpaceNode *snode, const bNode *node) +{ + Vector<NodeExtraInfoRow> rows; + if (!(snode->overlay.flag & SN_OVERLAY_SHOW_OVERLAYS)) { + return rows; + } + + if (snode->overlay.flag & SN_OVERLAY_SHOW_TIMINGS && snode->edittree->type == NTREE_GEOMETRY && + (ELEM(node->typeinfo->nclass, NODE_CLASS_GEOMETRY, NODE_CLASS_GROUP, NODE_CLASS_ATTRIBUTE) || + ELEM(node->type, NODE_FRAME, NODE_GROUP_OUTPUT))) { + NodeExtraInfoRow row; + row.text = node_get_execution_time_label(snode, node); + if (!row.text.empty()) { + row.tooltip = TIP_( + "The execution time from the node tree's latest evaluation. For frame and group nodes, " + "the time for all sub-nodes"); + row.icon = ICON_PREVIEW_RANGE; + rows.append(std::move(row)); + } + } + return rows; +} + +static void node_draw_extra_info_row(const bNode *node, + const rctf *rect, + const int row, + const NodeExtraInfoRow &extra_info_row) +{ + uiBut *but_timing = uiDefBut(node->block, + UI_BTYPE_LABEL, + 0, + extra_info_row.text.c_str(), + (int)(rect->xmin + 4.0f * U.dpi_fac + NODE_MARGIN_X + 0.4f), + (int)(rect->ymin + row * (20.0f * U.dpi_fac)), + (short)(rect->xmax - rect->xmin), + (short)NODE_DY, + nullptr, + 0, + 0, + 0, + 0, + ""); + UI_block_emboss_set(node->block, UI_EMBOSS_NONE); + uiBut *but_icon = uiDefIconBut(node->block, + UI_BTYPE_BUT, + 0, + extra_info_row.icon, + (int)(rect->xmin + 6.0f * U.dpi_fac), + (int)(rect->ymin + row * (20.0f * U.dpi_fac)), + NODE_HEADER_ICON_SIZE * 0.8f, + UI_UNIT_Y, + nullptr, + 0, + 0, + 0, + 0, + extra_info_row.tooltip); + UI_block_emboss_set(node->block, UI_EMBOSS); + if (node->flag & NODE_MUTED) { + UI_but_flag_enable(but_timing, UI_BUT_INACTIVE); + UI_but_flag_enable(but_icon, UI_BUT_INACTIVE); + } +} + +void node_draw_extra_info_panel(const SpaceNode *snode, const bNode *node) +{ + Vector<NodeExtraInfoRow> extra_info_rows = node_get_extra_info(snode, node); + + if (extra_info_rows.size() == 0) { + return; + } + + const rctf *rct = &node->totr; + float color[4]; + rctf extra_info_rect; + + if (node->type == NODE_FRAME) { + extra_info_rect.xmin = rct->xmin; + extra_info_rect.xmax = rct->xmin + 95.0f * U.dpi_fac; + extra_info_rect.ymin = rct->ymin + 2.0f * U.dpi_fac; + extra_info_rect.ymax = rct->ymin + 2.0f * U.dpi_fac; + } + else { + extra_info_rect.xmin = rct->xmin + 3.0f * U.dpi_fac; + extra_info_rect.xmax = rct->xmin + 95.0f * U.dpi_fac; + extra_info_rect.ymin = rct->ymax; + extra_info_rect.ymax = rct->ymax + extra_info_rows.size() * (20.0f * U.dpi_fac); + + if (node->flag & NODE_MUTED) { + UI_GetThemeColorBlend4f(TH_BACK, TH_NODE, 0.2f, color); + } + else { + UI_GetThemeColorBlend4f(TH_BACK, TH_NODE, 0.75f, color); + } + color[3] -= 0.35f; + UI_draw_roundbox_corner_set( + UI_CNR_ALL & ~UI_CNR_BOTTOM_LEFT & + ((rct->xmax) > extra_info_rect.xmax ? ~UI_CNR_BOTTOM_RIGHT : UI_CNR_ALL)); + UI_draw_roundbox_4fv(&extra_info_rect, true, BASIS_RAD, color); + + /* Draw outline. */ + const float outline_width = 1.0f; + extra_info_rect.xmin = rct->xmin + 3.0f * U.dpi_fac - outline_width; + extra_info_rect.xmax = rct->xmin + 95.0f * U.dpi_fac + outline_width; + extra_info_rect.ymin = rct->ymax - outline_width; + extra_info_rect.ymax = rct->ymax + outline_width + + extra_info_rows.size() * (20.0f * U.dpi_fac); + + UI_GetThemeColorBlendShade4fv(TH_BACK, TH_NODE, 0.4f, -20, color); + UI_draw_roundbox_corner_set( + UI_CNR_ALL & ~UI_CNR_BOTTOM_LEFT & + ((rct->xmax) > extra_info_rect.xmax ? ~UI_CNR_BOTTOM_RIGHT : UI_CNR_ALL)); + UI_draw_roundbox_4fv(&extra_info_rect, false, BASIS_RAD, color); + } + + for (int row : extra_info_rows.index_range()) { + node_draw_extra_info_row(node, &extra_info_rect, row, extra_info_rows[row]); + } +} + static void node_draw_basis(const bContext *C, const View2D *v2d, const SpaceNode *snode, @@ -1602,6 +1835,8 @@ static void node_draw_basis(const bContext *C, GPU_line_width(1.0f); + node_draw_extra_info_panel(snode, node); + /* Header. */ { const rctf rect = { diff --git a/source/blender/editors/space_node/node_intern.hh b/source/blender/editors/space_node/node_intern.hh index 2e973def867..6dc57c1fb79 100644 --- a/source/blender/editors/space_node/node_intern.hh +++ b/source/blender/editors/space_node/node_intern.hh @@ -96,6 +96,7 @@ void node_link_calculate_multi_input_position(const float socket_x, float r[2]); int node_get_colorid(bNode *node); +void node_draw_extra_info_panel(const SpaceNode *snode, const bNode *node); int node_get_resize_cursor(int directions); void node_draw_shadow(const SpaceNode *snode, const bNode *node, float radius, float alpha); void node_draw_default(const bContext *C, diff --git a/source/blender/makesdna/DNA_space_types.h b/source/blender/makesdna/DNA_space_types.h index 7fb15fc8508..88c5ace9cb3 100644 --- a/source/blender/makesdna/DNA_space_types.h +++ b/source/blender/makesdna/DNA_space_types.h @@ -1520,6 +1520,7 @@ typedef struct SpaceNodeOverlay { typedef enum eSpaceNodeOverlay_Flag { SN_OVERLAY_SHOW_OVERLAYS = (1 << 1), SN_OVERLAY_SHOW_WIRE_COLORS = (1 << 2), + SN_OVERLAY_SHOW_TIMINGS = (1 << 3), } eSpaceNodeOverlay_Flag; typedef struct SpaceNode { diff --git a/source/blender/makesrna/intern/rna_space.c b/source/blender/makesrna/intern/rna_space.c index e7bcd387eaf..8f04524c5c1 100644 --- a/source/blender/makesrna/intern/rna_space.c +++ b/source/blender/makesrna/intern/rna_space.c @@ -7110,6 +7110,12 @@ static void rna_def_space_node_overlay(BlenderRNA *brna) RNA_def_property_ui_text( prop, "Show Wire Colors", "Color node links based on their connected sockets"); RNA_def_property_update(prop, NC_SPACE | ND_SPACE_NODE, NULL); + + prop = RNA_def_property(srna, "show_timing", PROP_BOOLEAN, PROP_NONE); + RNA_def_property_boolean_sdna(prop, NULL, "overlay.flag", SN_OVERLAY_SHOW_TIMINGS); + RNA_def_property_boolean_default(prop, false); + RNA_def_property_ui_text(prop, "Show Timing", "Display each node's last execution time"); + RNA_def_property_update(prop, NC_SPACE | ND_SPACE_NODE, NULL); } static void rna_def_space_node(BlenderRNA *brna) diff --git a/source/blender/modifiers/intern/MOD_nodes_evaluator.cc b/source/blender/modifiers/intern/MOD_nodes_evaluator.cc index 4d081450fd8..e23c494f7cf 100644 --- a/source/blender/modifiers/intern/MOD_nodes_evaluator.cc +++ b/source/blender/modifiers/intern/MOD_nodes_evaluator.cc @@ -35,6 +35,8 @@ #include "BLI_task.hh" #include "BLI_vector_set.hh" +#include <chrono> + namespace blender::modifiers::geometry_nodes { using fn::CPPType; @@ -929,7 +931,13 @@ class GeometryNodesEvaluator { params.error_message_add(geo_log::NodeWarningType::Legacy, TIP_("Legacy node will be removed before Blender 4.0")); } + using Clock = std::chrono::steady_clock; + Clock::time_point begin = Clock::now(); bnode.typeinfo->geometry_node_execute(params); + Clock::time_point end = Clock::now(); + const std::chrono::microseconds duration = + std::chrono::duration_cast<std::chrono::microseconds>(end - begin); + params_.geo_logger->local().log_execution_time(node, duration); } void execute_multi_function_node(const DNode node, diff --git a/source/blender/nodes/NOD_geometry_nodes_eval_log.hh b/source/blender/nodes/NOD_geometry_nodes_eval_log.hh index 2a118057a03..0fbc1803db6 100644 --- a/source/blender/nodes/NOD_geometry_nodes_eval_log.hh +++ b/source/blender/nodes/NOD_geometry_nodes_eval_log.hh @@ -41,6 +41,8 @@ #include "NOD_derived_node_tree.hh" +#include <chrono> + struct SpaceNode; struct SpaceSpreadsheet; @@ -169,6 +171,11 @@ struct NodeWithWarning { NodeWarning warning; }; +struct NodeWithExecutionTime { + DNode node; + std::chrono::microseconds exec_time; +}; + /** The same value can be referenced by multiple sockets when they are linked. */ struct ValueOfSockets { Span<DSocket> sockets; @@ -189,6 +196,7 @@ class LocalGeoLogger { std::unique_ptr<LinearAllocator<>> allocator_; Vector<ValueOfSockets> values_; Vector<NodeWithWarning> node_warnings_; + Vector<NodeWithExecutionTime> node_exec_times_; friend ModifierLog; @@ -201,6 +209,7 @@ class LocalGeoLogger { void log_value_for_sockets(Span<DSocket> sockets, GPointer value); void log_multi_value_socket(DSocket socket, Span<GPointer> values); void log_node_warning(DNode node, NodeWarningType type, std::string message); + void log_execution_time(DNode node, std::chrono::microseconds exec_time); }; /** The root logger class. */ @@ -274,12 +283,14 @@ class NodeLog { Vector<SocketLog> input_logs_; Vector<SocketLog> output_logs_; Vector<NodeWarning, 0> warnings_; + std::chrono::microseconds exec_time_; friend ModifierLog; public: const SocketLog *lookup_socket_log(eNodeSocketInOut in_out, int index) const; const SocketLog *lookup_socket_log(const bNode &node, const bNodeSocket &socket) const; + void execution_time(std::chrono::microseconds exec_time); Span<SocketLog> input_logs() const { @@ -296,6 +307,11 @@ class NodeLog { return warnings_; } + std::chrono::microseconds execution_time() const + { + return exec_time_; + } + Vector<const GeometryAttributeInfo *> lookup_available_attributes() const; }; diff --git a/source/blender/nodes/intern/geometry_nodes_eval_log.cc b/source/blender/nodes/intern/geometry_nodes_eval_log.cc index 782ab43336c..4cba9669647 100644 --- a/source/blender/nodes/intern/geometry_nodes_eval_log.cc +++ b/source/blender/nodes/intern/geometry_nodes_eval_log.cc @@ -25,6 +25,8 @@ #include "BLT_translation.h" +#include <chrono> + namespace blender::nodes::geometry_nodes_eval_log { using fn::CPPType; @@ -64,6 +66,12 @@ ModifierLog::ModifierLog(GeoLogger &logger) node_with_warning.node); node_log.warnings_.append(node_with_warning.warning); } + + for (NodeWithExecutionTime &node_with_exec_time : local_logger.node_exec_times_) { + NodeLog &node_log = this->lookup_or_add_node_log(log_by_tree_context, + node_with_exec_time.node); + node_log.exec_time_ = node_with_exec_time.exec_time; + } } } @@ -471,4 +479,9 @@ void LocalGeoLogger::log_node_warning(DNode node, NodeWarningType type, std::str node_warnings_.append({node, {type, std::move(message)}}); } +void LocalGeoLogger::log_execution_time(DNode node, std::chrono::microseconds exec_time) +{ + node_exec_times_.append({node, exec_time}); +} + } // namespace blender::nodes::geometry_nodes_eval_log |