Source: https://dev-docs.nebula-graph.io/v5.3.2/database-gql-reference/data-admin/tuning/profile/ Documentation version: v5.3.2 # PROFILE command The `PROFILE` command executes a query, produces output, and collects runtime information for each operator in the execution plan. When using the ngql CLI, you can use the `:planstyle` command to switch between execution plan display styles (nest/table/box). The default style is nest. For more information, see [Execution plan style setting](https://dev-docs.nebula-graph.io/v5.3.2/utilities/ngql/usage/#execution_plan_style_setting) in the ngql documentation. MATCH expansion-order changes are disabled by default The optimizer's ability to change the expansion order of `MATCH` patterns is controlled by the session-level option `enable_reorder`, whose default value is `false`. When reordering is disabled, the planner prefers the textual expansion order when possible, while still using valid fallback plans and specialized traversal operators for supported cases. To inspect or debug reorder behavior, you can: - Temporarily enable reordering with `SESSION SET enable_reorder = true` or `/*+ SET_VAR(enable_reorder=true) */` when you want to compare reordered plans. - Use `EXPLAIN CBO` to view the logical plan after the CBO stage. For more information, see [EXPLAIN](https://dev-docs.nebula-graph.io/v5.3.2/database-gql-reference/data-admin/tuning/explain/). - Enable CBO trace logging (by setting `enable_cbo_trace` to `true`) to view the CBO's detailed decision-making process in the logs. For more information, see [Specify `CBO` to view the logical plan after CBO reordering](https://dev-docs.nebula-graph.io/v5.3.2/database-gql-reference/data-admin/tuning/explain/). ## Syntax diagramsource profile_command ```` profile_command ::= 'PROFILE' ( 'format' '=' '"' ( 'verbose' | 'default' ) '"' )? gql_query ```` ## Parameters ### `format = "verbose" | format = "default"` There are two output formats for the execution plan: `verbose` and `default`. - The `verbose` format is more detailed and is suitable for debugging and optimizing queries. When the `format = verbose` option is specified, the following information is returned: | Parameter | Description | `plan` | Represents the operators in the execution plan. Operators are listed in bottom-to-top execution order. | `details` | Provides detailed information about the operator, including the data of nodes and edges to be accessed. | `time(ms)` | Represents the time spent by the operator in milliseconds. | `rows` | Represents the number of rows produced by the operator. | `memory(KiB)` | Represents the memory usage of the operator. | `blocked(ms)` | Represents the total blocking time at runtime. | `queued(ms)` | Represents the total queuing time at runtime. | `consume(ms)` | Represents the total consume time at runtime. | `produce(ms)` | Represents the total produce time at runtime. | `finish(ms)` | Represents the total finish time at runtime. | `batches` | Represents the number of batches computed by the operator. | `concurrency` | Represents the number of concurrent tasks for the operator. | `others` | Represents other information about the operator. - The `default` format is a simplified version of the `verbose` format. When both the `format = default` and `format = "verbose"` options are omitted, the `default` format is used by default, returning the following information: | Parameter | Description | `plan` | Represents the operators in the execution plan. | `details` | Provides detailed information about the operator, including the data of nodes and edges to be accessed. | `time(ms)` | Represents the time spent by the operator in milliseconds. | `rows` | Represents the number of rows produced by the operator. | `memory(KiB)` | Represents the memory usage of the operator. | `blocked(ms)` | Represents the total blocking time at runtime. ### `gql_query` The GQL query whose execution plan is to be displayed. ## Examples The following examples are based on the [example dataset](https://dev-docs.nebula-graph.io/v5.3.2/database-gql-reference/overview/example-dataset/). ### Use `default` to display a simplified execution plan The following command uses the `format="default"` option to display the query results and the corresponding execution plan. You can also omit the `format="default"` option since the default format is `default`. #### View nested execution plan ```` PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` Returns: ```` +------------------------------------------------------------------+ | b | +------------------------------------------------------------------+ | (289214134115893249@Movie:Movie{id:486,name:"Realization Time"}) | +------------------------------------------------------------------+ Got 1 rows (time spent 19.05ms/20.456376ms) • [P0]CallbackSink │ details: Offset:0, Limit:1, Partial:false, Approx │ :false │ time(ms): 0.00 │ rows: 1 │ memory(KiB): 0.00 │ blocked(ms): 0.00 │ └── • [P0]Limit │ details: Offset:0, Limit:1, Partial:false, Approx │ :false │ time(ms): 0.03 │ rows: 1 │ memory(KiB): 4.50 │ blocked(ms): 0.00 │ └── • [P0]HashJoinProbe │ details: Project: b, element_id(b)=_right_node_i │ d(e) │ time(ms): 0.20 │ rows: 943 │ memory(KiB): 50.49 │ blocked(ms): 11.82 │ ├── • [P0]StorageRemoteAccess │ │ details: TableScan: {Movie: {name, id}}, b{} │ │ time(ms): 0.00 │ │ rows: 29 │ │ memory(KiB): 0.00 │ │ blocked(ms): 1.09 │ │ │ └── • [SP0]CallbackSink │ │ details: TableScan: UNKNOWN, b{} │ │ time(ms): 0.01 │ │ rows: 158 │ │ memory(KiB): 0.00 │ │ blocked(ms): 0.00 │ │ │ └── • [SP0]NodesScan │ details: TableScan: UNKNOWN, b{} │ time(ms): 1.84 │ rows: 158 │ memory(KiB): 85.02 │ blocked(ms): 0.00 │ └── • [P1]HashJoinBuild │ details: Project: b, element_id(b)=_right_node_i │ d(e) │ time(ms): 1.01 │ rows: 240 │ memory(KiB): 450.25 │ blocked(ms): 0.00 │ └── • [P1]StorageRemoteAccess │ details: in(node_type_id(_left_node_id(e)), [1024 │ ,1025,1026]) │ time(ms): 0.01 │ rows: 7891 │ memory(KiB): 0.00 │ blocked(ms): 9.39 │ └── • [SP0]CallbackSink │ details: in(node_type_id(_left_node_id(e)), [1024 │ ,1025,1026]) │ time(ms): 0.27 │ rows: 7891 │ memory(KiB): 0.00 │ blocked(ms): 0.00 │ └── • [SP0]Filter │ details: in(node_type_id(_left_node_id(e)), [1024 │ ,1025,1026]) │ time(ms): 1.80 │ rows: 7891 │ memory(KiB): 4.93 │ blocked(ms): 0.00 │ └── • [SP0]EdgesScan details: direction: outgoing: true, incoming: fal se, undirected0: false, undirected1: fal se, TableScan: UNKNOWN, TableScan: UNKNO WN, TableScan: UNKNOWN, e{} time(ms): 10.26 rows: 7891 memory(KiB): 128.44 blocked(ms): 0.00 Execution Plan: [Px] means pipeline-x and [S] means storage side. Elapsed Time: parse time : 713 us build time : 1126 us optimize time : 1120 us serialize time: 504 us total time : 19050 us ```` The first table shows the query results, and the nested view below shows the execution plan for the query. Each level corresponds to an operator, and the indentation between levels indicates the dependency between operators. #### View table execution plan You can use the `:planstyle` command to switch the execution plan display view to table format. For more information, see [Set execution plan display view](https://dev-docs.nebula-graph.io/v5.3.2/utilities/ngql/usage/#execution-plan-style-setting). ```` :planstyle table PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` Returns: ```` +--------------------------------------------------------------+ | b | +--------------------------------------------------------------+ | (289309336360976385@Movie:Movie{id:478,name:"Rest in Pain"}) | +--------------------------------------------------------------+ Got 1 rows (time spent 13.164ms/14.335678ms) +---------------------------------+------------------------------------------------------------------------------------------------------+----------+------+-------------+-------------+ | plan | details | time(ms) | rows | memory(KiB) | blocked(ms) | +---------------------------------+------------------------------------------------------------------------------------------------------+----------+------+-------------+-------------+ | [P0]CallbackSink | Offset:0, Limit:1, Partial:false, Approx:false | 0.01 | 1 | 0.00 | 0.00 | | └─[P0]Limit | Offset:0, Limit:1, Partial:false, Approx:false | 0.01 | 1 | 0.44 | 0.00 | | └─[P0]HashJoinProbe | Project: b, element_id(b)=_right_node_id(e) | 0.10 | 777 | 47.93 | 9.23 | | ├─[P0]StorageRemoteAccess | TableScan: {Movie: {name, id}}, b{} | 0.00 | 25 | 0.00 | 1.58 | | │ └─[SP0]CallbackSink | TableScan: UNKNOWN, b{} | 0.00 | 25 | 0.00 | 0.00 | | │ └─[SP0]NodesScan | TableScan: UNKNOWN, b{} | 0.11 | 25 | 85.02 | 0.00 | | └─[P1]HashJoinBuild | Project: b, element_id(b)=_right_node_id(e) | 0.64 | 240 | 450.25 | 0.00 | | └─[P1]StorageRemoteAccess | in(node_type_id(_left_node_id(e)), [1024,1025,1026]) | 0.01 | 7891 | 0.00 | 7.43 | | └─[SP0]CallbackSink | in(node_type_id(_left_node_id(e)), [1024,1025,1026]) | 0.17 | 7891 | 0.00 | 0.00 | | └─[SP0]Filter | in(node_type_id(_left_node_id(e)), [1024,1025,1026]) | 1.20 | 7891 | 5.39 | 0.00 | | └─[SP0]EdgesScan | direction: outgoing: true, incoming: false, undirected0: false, undirected1: false, TableScan: UN... | 5.93 | 7891 | 128.44 | 0.00 | +---------------------------------+------------------------------------------------------------------------------------------------------+----------+------+-------------+-------------+ Execution Plan: [Px] means pipeline-x and [S] means storage side. Elapsed Time: parse time : 194 us build time : 233 us optimize time : 353 us serialize time: 70 us total time : 13164 us ```` The first table shows the query results, and the second table shows the execution plan in table view. Each row in the table corresponds to an operator. The indentation in the `plan` column indicates the dependency between operators. #### View box execution plan You can use the `:planstyle` command to switch the execution plan display view to box format. For more information, see [Set execution plan display view](https://dev-docs.nebula-graph.io/v5.3.2/utilities/ngql/usage/#execution-plan-style-setting). ```` :planstyle box PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` Returns: ```` +------------------------------------------------------------------+ | b | +------------------------------------------------------------------+ | (289214134115893249@Movie:Movie{id:486,name:"Realization Time"}) | +------------------------------------------------------------------+ Got 1 rows (time spent 14.299ms/15.133846ms) ┌──────────────────────────────────────┐ │ [P0]CallbackSink │ │ -------------------------------- │ │ Offset:0, Limit:1, Partial:false │ │ , Approx:false │ │ -------------------------------- │ │ time(ms): 0.00 │ │ -------------------------------- │ │ rows: 1 │ │ -------------------------------- │ │ memory(KiB): 0.00 │ │ -------------------------------- │ │ blocked(ms): 0.00 │ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ │ [P0]Limit │ │ -------------------------------- │ │ Offset:0, Limit:1, Partial:false │ │ , Approx:false │ │ -------------------------------- │ │ time(ms): 0.01 │ │ -------------------------------- │ │ rows: 1 │ │ -------------------------------- │ │ memory(KiB): 4.50 │ │ -------------------------------- │ │ blocked(ms): 0.00 │ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ │ [P0]HashJoinProbe │ │ -------------------------------- │ │ Project: b, element_id(b)=_righ │ │ t_node_id(e) │ │ -------------------------------- │ │ time(ms): 0.09 │ │ -------------------------------- │────────────────────┐ │ rows: 943 │ │ │ -------------------------------- │ │ │ memory(KiB): 50.49 │ │ │ -------------------------------- │ │ │ blocked(ms): 11.12 │ │ └──────────────────┬───────────────────┘ │ ┌──────────────────┴───────────────────┐ ┌──────────────────┴───────────────────┐ │ [P0]StorageRemoteAccess │ │ [P1]HashJoinBuild │ │ -------------------------------- │ │ -------------------------------- │ │ TableScan: {Movie: {name, id}}, │ │ Project: b, element_id(b)=_righ │ │ b{} │ │ t_node_id(e) │ │ -------------------------------- │ │ -------------------------------- │ │ time(ms): 0.00 │ │ time(ms): 0.70 │ │ -------------------------------- │ │ -------------------------------- │ │ rows: 29 │ │ rows: 240 │ │ -------------------------------- │ │ -------------------------------- │ │ memory(KiB): 0.00 │ │ memory(KiB): 450.25 │ │ -------------------------------- │ │ -------------------------------- │ │ blocked(ms): 0.67 │ │ blocked(ms): 0.00 │ └──────────────────┬───────────────────┘ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ ┌──────────────────┴───────────────────┐ │ [SP0]CallbackSink │ │ [P1]StorageRemoteAccess │ │ -------------------------------- │ │ -------------------------------- │ │ TableScan: UNKNOWN, b{} │ │ in(node_type_id(_left_node_id(e) │ │ │ │ ), [1024,1025,1026]) │ │ -------------------------------- │ │ -------------------------------- │ │ time(ms): 0.02 │ │ time(ms): 0.01 │ │ -------------------------------- │ │ -------------------------------- │ │ rows: 157 │ │ rows: 7891 │ │ -------------------------------- │ │ -------------------------------- │ │ memory(KiB): 0.00 │ │ memory(KiB): 0.00 │ │ -------------------------------- │ │ -------------------------------- │ │ blocked(ms): 0.00 │ │ blocked(ms): 9.73 │ └──────────────────┬───────────────────┘ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ ┌──────────────────┴───────────────────┐ │ [SP0]NodesScan │ │ [SP0]CallbackSink │ │ -------------------------------- │ │ -------------------------------- │ │ TableScan: UNKNOWN, b{} │ │ in(node_type_id(_left_node_id(e) │ │ │ │ ), [1024,1025,1026]) │ │ -------------------------------- │ │ -------------------------------- │ │ time(ms): 0.79 │ │ time(ms): 0.31 │ │ -------------------------------- │ │ -------------------------------- │ │ rows: 157 │ │ rows: 7891 │ │ -------------------------------- │ │ -------------------------------- │ │ memory(KiB): 85.02 │ │ memory(KiB): 0.00 │ │ -------------------------------- │ │ -------------------------------- │ │ blocked(ms): 0.00 │ │ blocked(ms): 0.00 │ └──────────────────────────────────────┘ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ │ [SP0]Filter │ │ -------------------------------- │ │ in(node_type_id(_left_node_id(e) │ │ ), [1024,1025,1026]) │ │ -------------------------------- │ │ time(ms): 1.06 │ │ -------------------------------- │ │ rows: 7891 │ │ -------------------------------- │ │ memory(KiB): 5.13 │ │ -------------------------------- │ │ blocked(ms): 0.00 │ └──────────────────┬───────────────────┘ ┌──────────────────┴───────────────────┐ │ [SP0]EdgesScan │ │ -------------------------------- │ │ direction: outgoing: true, incom │ │ ing: false, undirected0: false, │ │ undirected1: false, TableScan: U │ │ NKNOWN, TableScan: UNKNOWN, Tabl │ │ eScan: UNKNOWN, e{} │ │ -------------------------------- │ │ time(ms): 5.89 │ │ -------------------------------- │ │ rows: 7891 │ │ -------------------------------- │ │ memory(KiB): 128.44 │ │ -------------------------------- │ │ blocked(ms): 0.00 │ └──────────────────────────────────────┘ Execution Plan: [Px] means pipeline-x and [S] means storage side. Elapsed Time: parse time : 171 us build time : 188 us optimize time : 311 us serialize time: 43 us total time : 14299 us ```` The first table shows the query results, and the box structure below shows the execution plan. Each box represents an operator, and the connections between boxes indicate that the upper operator depends on the output of the lower operator. ### Use `verbose` to display a detailed execution plan ```` PROFILE format= "verbose" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` The above example uses the `verbose` format by specifying `format = "verbose"` to display the results and corresponding execution plan for the query `USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b`. Returns: ```` +-----------------------------------------------------------------+ | b | +-----------------------------------------------------------------+ | (289255176823373825@Movie:Movie{id:485,name:"Cooper's Dreams"}) | +-----------------------------------------------------------------+ Got 1 rows (time spent 19.451ms/20.555367ms) • [P0]CallbackSink │ details: Offset:0, Limit:1, Partial:false, Approx │ :false │ time(ms): 0.00 │ rows: 1 │ memory(KiB): 0.00 │ blocked(ms): 0.00 │ queued(ms): 0.07 │ consume(ms): 0.00 │ produce(ms): 0.00 │ finish(ms): 0.00 │ batches: 1 │ concurrency: 1 │ └── • [P0]Limit │ details: Offset:0, Limit:1, Partial:false, Approx │ :false │ time(ms): 0.02 │ rows: 1 │ memory(KiB): 4.50 │ blocked(ms): 0.00 │ queued(ms): 0.00 │ consume(ms): 0.00 │ produce(ms): 0.02 │ finish(ms): 0.00 │ batches: 1 │ concurrency: 1 │ └── • [P0]HashJoinProbe │ details: Project: b:NodeRef<(Movie)>, element_id │ (b::NodeRef<(Movie)>)::INT64=(_right_nod │ e_id(e::EdgeRef<(Actor)-[Act]->(Movie), │ (Director)-[Direct]->(Movie), (User)-[Wa │ tch]->(Movie)>))::INT64 │ time(ms): 0.19 │ rows: 486 │ memory(KiB): 32.31 │ blocked(ms): 14.71 │ queued(ms): 0.01 │ consume(ms): 0.02 │ produce(ms): 0.17 │ finish(ms): 0.00 │ batches: 1 │ concurrency: 1 │ others: {"joinProbe":"22/22 100%"} │ ├── • [P0]StorageRemoteAccess │ │ details: TableScan: {Movie: {name, id}}, b{} │ │ time(ms): 0.00 │ │ rows: 22 │ │ memory(KiB): 0.00 │ │ blocked(ms): 0.85 │ │ queued(ms): 0.16 │ │ consume(ms): 0.00 │ │ produce(ms): 0.00 │ │ finish(ms): 0.00 │ │ batches: 1 │ │ concurrency: 1 │ │ │ └── • [SP0]CallbackSink │ │ details: TableScan: {Movie: {name, id}}, b{} │ │ time(ms): 0.02 │ │ rows: 142 │ │ memory(KiB): 0.00 │ │ blocked(ms): 0.00 │ │ queued(ms): 0.51 │ │ consume(ms): 0.02 │ │ produce(ms): 0.00 │ │ finish(ms): 0.00 │ │ batches: 6 │ │ concurrency: 1 │ │ │ └── • [SP0]NodesScan │ details: TableScan: {Movie: {name, id}}, b{} │ time(ms): 0.77 │ rows: 142 │ memory(KiB): 85.02 │ blocked(ms): 0.00 │ queued(ms): 0.00 │ consume(ms): 0.00 │ produce(ms): 0.77 │ finish(ms): 0.00 │ batches: 6 │ concurrency: 1 │ └── • [P1]HashJoinBuild │ details: Project: b:NodeRef<(Movie)>, element_id │ (b::NodeRef<(Movie)>)::INT64=(_right_nod │ e_id(e::EdgeRef<(Actor)-[Act]->(Movie), │ (Director)-[Direct]->(Movie), (User)-[Wa │ tch]->(Movie)>))::INT64 │ time(ms): 0.89 │ rows: 240 │ memory(KiB): 450.25 │ blocked(ms): 0.00 │ queued(ms): 0.09 │ consume(ms): 0.36 │ produce(ms): 0.01 │ finish(ms): 0.52 │ batches: 0 │ concurrency: 1 │ others: {"joinDynamicFilter":240,"joinBridge":24 │ 0} │ └── • [P1]StorageRemoteAccess │ details: (in((node_type_id((_left_node_id(e::Edge │ Ref<(Actor)-[Act]->(Movie), (Director)-[ │ Direct]->(Movie), (User)-[Watch]->(Movie │ )>))::INT64))::INT16, [1024,1025,1026]:: │ LIST))::BOOL │ time(ms): 0.01 │ rows: 7891 │ memory(KiB): 0.00 │ blocked(ms): 12.74 │ queued(ms): 0.27 │ consume(ms): 0.00 │ produce(ms): 0.01 │ finish(ms): 0.00 │ batches: 10 │ concurrency: 1 │ └── • [SP0]CallbackSink │ details: (in((node_type_id((_left_node_id(e::Edge │ Ref<(Actor)-[Act]->(Movie), (Director)-[ │ Direct]->(Movie), (User)-[Watch]->(Movie │ )>))::INT64))::INT16, [1024,1025,1026]:: │ LIST))::BOOL │ time(ms): 0.24 │ rows: 7891 │ memory(KiB): 0.00 │ blocked(ms): 0.00 │ queued(ms): 17.95 │ consume(ms): 0.23 │ produce(ms): 0.01 │ finish(ms): 0.00 │ batches: 30 │ concurrency: 1 │ └── • [SP0]Filter │ details: (in((node_type_id((_left_node_id(e::Edge │ Ref<(Actor)-[Act]->(Movie), (Director)-[ │ Direct]->(Movie), (User)-[Watch]->(Movie │ )>))::INT64))::INT16, [1024,1025,1026]:: │ LIST))::BOOL │ time(ms): 1.34 │ rows: 7891 │ memory(KiB): 3.97 │ blocked(ms): 0.00 │ queued(ms): 0.00 │ consume(ms): 0.01 │ produce(ms): 1.33 │ finish(ms): 0.00 │ batches: 30 │ concurrency: 1 │ └── • [SP0]EdgesScan details: direction: outgoing: true, incoming: fal se, undirected0: false, undirected1: fal se, TableScan: {Watch: {}}, TableScan: { Direct: {}}, TableScan: {Act: {}}, e{} time(ms): 6.08 rows: 7891 memory(KiB): 128.44 blocked(ms): 0.00 queued(ms): 0.00 consume(ms): 0.00 produce(ms): 6.08 finish(ms): 0.00 batches: 30 concurrency: 1 Execution Plan: [Px] means pipeline-x and [S] means storage side. Elapsed Time: parse time : 416 us build time : 592 us optimize time : 583 us serialize time: 136 us total time : 19451 us ```` The first table shows the query results, and the nested view below shows the execution plan for the query. Each level of the nested view corresponds to an operator, and the indentation between levels indicates the dependency between operators.