PROFILE¶
PROFILE命令执行查询,生成输出,并收集执行计划中每个算子的运行时信息。
若使用 ngql 命令行工具,可通过:planstyle命令切换执行计划的展示形式(嵌套/表格/盒状)。默认风格为嵌套视图。更多信息,请参见 ngql 的设置执行计划展示视图。
MATCH 展开顺序重排默认关闭
MATCH模式的展开顺序重排由会话级配置项enable_reorder控制,默认值为false。关闭重排后,只要查询可执行,规划器会优先按查询文本顺序展开;对于受支持的场景,仍会使用有效的回退计划和专用遍历算子。
如需查看或调试重排行为,可以:
- 在需要对比重排计划时,临时执行
SESSION SET enable_reorder = true,或在单条查询前添加/*+ SET_VAR(enable_reorder=true) */。 - 使用
EXPLAIN CBO查看 CBO 阶段后的逻辑计划。更多信息,请参见 EXPLAIN。 - 启用 CBO 决策跟踪日志(通过设置
enable_cbo_trace为true),在日志中查看 CBO 的详细决策过程。更多信息,请参见指定CBO查看 CBO 重排序后的逻辑计划。
语法¶
- 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 查询。
示例¶
以下示例基于示例数据集。
使用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 的设置执行计划展示视图。
: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 的设置执行计划展示视图。
: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<INT16>))::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<INT16>))::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<INT16>))::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
第一张表是查询结果,下方嵌套格式则是查询的执行计划。嵌套视图的每一层都对应一个算子,嵌套视图层级间的缩进表示算子间的依赖关系。