Source: https://dev-docs.yueshu.com.cn/v5.3.2/database-gql-reference/data-admin/tuning/profile/ Documentation version: v5.3.2 # PROFILE `PROFILE`命令执行查询,生成输出,并收集执行计划中每个算子的运行时信息。 若使用 ngql 命令行工具,可通过`:planstyle`命令切换执行计划的展示形式(嵌套/表格/盒状)。默认风格为嵌套视图。更多信息,请参见 ngql 的[设置执行计划展示视图](https://dev-docs.yueshu.com.cn/v5.3.2/utilities/ngql/usage/#_10)。 MATCH 展开顺序重排默认关闭 `MATCH`模式的展开顺序重排由会话级配置项`enable_reorder`控制,默认值为`false`。关闭重排后,只要查询可执行,规划器会优先按查询文本顺序展开;对于受支持的场景,仍会使用有效的回退计划和专用遍历算子。 如需查看或调试重排行为,可以: - 在需要对比重排计划时,临时执行`SESSION SET enable_reorder = true`,或在单条查询前添加`/*+ SET_VAR(enable_reorder=true) */`。 - 使用`EXPLAIN CBO`查看 CBO 阶段后的逻辑计划。更多信息,请参见 [EXPLAIN](https://dev-docs.yueshu.com.cn/v5.3.2/database-gql-reference/data-admin/tuning/explain/)。 - 启用 CBO 决策跟踪日志(通过设置`enable_cbo_trace`为`true`),在日志中查看 CBO 的详细决策过程。更多信息,请参见[指定`CBO`查看 CBO 重排序后的逻辑计划](https://dev-docs.yueshu.com.cn/v5.3.2/database-gql-reference/data-admin/tuning/explain/)。 ## 语法 语法图源码 profile_command ```` profile_command ::= 'PROFILE' ( 'format' '=' '"' ( 'verbose' | 'default' ) '"' )? gql_query ```` ## 参数 ### `format = "verbose" | format = "default"` 执行计划的输出格式有两种:`verbose`和`default`。 - `verbose`格式更加详细,适用于调试和优化查询。当指定选项`format = verbose`时,返回以下信息: | 参数 | 描述 | `plan` | 表示执行计划的算子。算子按从下到上的执行顺序列出。 | `details` | 提供有关算子的详细信息,包括将访问的点和边的数据。 | `time(ms)` | 表示此算子花费的时间(毫秒)。 | `rows` | 表示此算子生成的行数。 | `memory(KiB)` | 表示此算子的内存使用量。 | `blocked(ms)` | 表示运行时的总阻塞时间。 | `queued(ms)` | 表示运行时的总排队时间。 | `consume(ms)` | 表示运行时的总消耗时间。 | `produce(ms)` | 表示运行时的总生成时间。 | `finish(ms)` | 表示运行时的总完成时间。 | `batches` | 表示此算子计算的批次数。 | `concurrency` | 表示此算子的并发任务数。 | `others` | 表示有关此算子的其他信息。 - `default`格式是`verbose`格式的简化版本。当省略选项`format = default`和`format = "verbose"`时,默认使用格式`default`,返回以下信息: | 参数 | 描述 | `plan` | 表示执行计划的算子。 | `details` | 提供有关算子的详细信息,包括将访问的点和边的数据。 | `time(ms)` | 表示此算子花费的时间(毫秒)。 | `rows` | 表示此算子生成的行数。 | `memory(KiB)` | 表示此算子的内存使用量。 | `blocked(ms)` | 表示运行时的总阻塞时间。 ### `gql_query` 待显示其执行计划的 GQL 查询。 ## 示例 以下示例基于[示例数据集](https://dev-docs.yueshu.com.cn/v5.3.2/database-gql-reference/overview/example-dataset/)。 ### 使用`default`显示简化的执行计划 下述命令使用选项`format="default"`显示查询结果及相应的执行计划。您也可以省略`format="default"`选项,因为默认格式就是`default`。 #### 查看嵌套视图执行计划 ```` PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` 返回: ```` +------------------------------------------------------------------+ | 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 ```` 第一张表是查询结果,下方嵌套视图则展示所查询的执行计划,每一层都对应一个算子。嵌套视图层级间的缩进表示算子间的依赖关系。 #### 查看表格视图执行计划 若使用 ngql 命令行工具,可通过`:planstyle`命令将执行计划展示为表格形式。更多信息,请参见 ngql 的[设置执行计划展示视图](https://dev-docs.yueshu.com.cn/v5.3.2/utilities/ngql/usage/#_10)。 ```` :planstyle table PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` 返回: ```` +--------------------------------------------------------------+ | 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 ```` 第一张表是查询结果,第二张表则为表格视图的执行计划,表格中的每一行对应一个算子。`plan`列中的缩进表示算子之间的依赖关系。 #### 查看盒状视图执行计划 若使用 ngql 命令行工具,可通过`:planstyle`命令将执行计划展示为盒状视图。更多信息,请参见 ngql 的[设置执行计划展示视图](https://dev-docs.yueshu.com.cn/v5.3.2/utilities/ngql/usage/#_10)。 ```` :planstyle box PROFILE format="default" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` 返回: ```` +------------------------------------------------------------------+ | 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 ```` 第一张表是查询结果,下面的盒状结构展示执行计划。每个方框代表一个算子,方框之间的连接表示上方算子依赖于下方算子的输出。 ### 使用`verbose`显示详细的执行计划 ```` PROFILE format= "verbose" USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b ```` 上述示例通过指定`format = "verbose"`使用`verbose`格式来显示查询`USE movie MATCH (a:Person)-[e]->(b@Movie) LIMIT 1 RETURN b`的结果和相应的执行计划。 返回: ```` +-----------------------------------------------------------------+ | 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 ```` 第一张表是查询结果,下方嵌套格式则是查询的执行计划。嵌套视图的每一层都对应一个算子,嵌套视图层级间的缩进表示算子间的依赖关系。