OceanBase 数据库全链路诊断功能可以记录由客户端到 OBProxy 再到 OBServer 全链路各阶段的耗时及各组件诊断相关的 Trace 信息。其中 Trace Log 记录的最小单元是一个 Span, 每个 Span 可以记录某一个执行区间或模块从开始执行到结束执行的时间以及相关信息(使用 Tags),来帮助运维人员理解数据库内部的处理逻辑以及定位问题所在。
Span 及 Tag 定义
Span 及 Tag 定义在 ob_trace_def.h 文件中, 分为 HIGH(Level 1)、MIDDLE(Level 2) 和 LOW(level 3) 三个级别,其中 HIGH 是默认设置级别,也就是默认会打印 Level 1 对应的 Span 和 Tag,如果需要打印其他级别的 Span 和 Tag,则需要通过控制命令将 Trace Level 值调高,Level 2 的 Span 可以给用户自己在分析问题时获得更多的 Span 信息,Level 3 Span 主要用于 OceanBase 数据库研发诊断问题时获得更详细的信息;于如果设置的 Level 值为 N,则 Trace 会打印 Level <= N 的 Span 和 Tag。
Span 的定义如下:
#define HIGH_LEVEL_SPAN
DEF_SPAN(span_type, comment)
#undef HIGH_LEVEL_SPAN
#define MIDDLE_LEVEL_SPAN
DEF_SPAN(span_type, comment)
#undef MIDDLE_LEVEL_SPAN
#define LOW_LEVEL_SPAN
DEF_SPAN(span_type, comment)
#undef LOW_LEVEL_SPAN
Tag 的定义如下:
#define HIGH_LEVEL_TAG
DEF_SPAN(tag_type, comment)
#undef HIGH_LEVEL_TAG
#define MIDDLE_LEVEL_TAG
DEF_SPAN(tag_type, comment)
#undef MIDDLE_LEVEL_TAG
#define LOW_LEVEL_TAG
DEF_SPAN(tag_type, comment)
#undef LOW_LEVEL_TAG
相关 Span 介绍如下:
com_query_entry:查询过程。mpquery_single_stmt:单个语句的访问路径。sql_compile:编译 SQL。pc_get_plan:获取执行计划。hard_parse: 硬解析。parse:软解析。resolve:解析语法树的语义并生成语句。rewrite:重写 SQL。optimize:进行基于成本的优化并生成执行计划日志。code_generate:根据执行计划日志生成物理执行计划。pc_add_plan:将生成的执行计划加入 Plan Cache。sql_execute:执行物理执行计划。open:打开执行计划。response_result:执行计划过程和结果。px_schedule:按照 PX 划分任务。px_task:执行 PX 子任务。close:关闭执行计划。cmd_execute:执行命令。cmd_open:关闭命令。ps_prepare:Preprocess Statement 的预处理。ps_execute:Preprocess Statement 的执行。ps_close:关闭 Preprocess Statement。pl_entry:存储过程处理。pl_compile:编译存储过程对象。pc_get_pl_object:从 Plan Cache 获取存储过程对象。pc_add_pl_object:把存储过程对象存储在 Plan Cache。pl_execute:执行存储过程。pl_spi_query:执行存储过程中的 SPI 语句。pl_spi_prepare:存储过程预处理阶段。pl_spi_execute:执行存储过程中的 SPI 语句。inner_prepare:内部 SQL 的预处理阶段。inner_execute:内部 SQL 的执行阶段。inner_execute_read:读内部 SQL。inner_execute_write:写内部 SQL。inner_commit:提交内部 SQL 事务。inner_rollback:回滚内部 SQL 事务。
相关 Tag 介绍如下:
com_query_entrylog_trace_id:当前请求在 Log 中的 Trace ID。err_code:当前请求的错误代码。
sql_compilesess_id:Session ID 。sql_text:SQL 文本。sql_id:SQL ID。hit_plan:执行计划命中执行计划缓存。
px_tasktask_id:并行任务的逻辑 ID。dfo_id:数据流操作 ID。sqc_id:子查询协调器 ID。qc_id:查询协调器 ID。group_id:资源组 ID。
px_scheduledfo_id:数据流操作 ID。used_worker_cnt:正在使用的 px 工作线程的个数。qc_id:查询协调器 ID。
ps_closeps_id:Preprocess Statement ID。
Trace Log 示例
运维人员可根据需要,通过使用 PL/SQL 程序包 DBMS_MONITOR 中相关方法,控制相关应用程序不同标识信息维度是否开启全链路诊断 Trace,以及该 Trace 的打点和相关信息打印到 Trace 日志的策略。日志打印会根据采样频率判断是否会被采样并记录到内存中,有一定的概率打印到 Trace 日志中。详细信息请参见 全链路诊断。 示例如下:
+-----------------------------------------------------------------------------------+----------------------------+------------+
| Operation | StartTime | ElapseTime |
+-----------------------------------------------------------------------------------+----------------------------+------------+
| com_query_process | 2022-10-26 11:46:52.613777 | 213196 µs |
| └── mpquery_single_stmt | 2022-10-26 11:46:52.613890 | 213062 µs |
| ├── sql_compile | 2022-10-26 11:46:52.613928 | 146291 µs |
| │ ├── pc_get_plan | 2022-10-26 11:46:52.613983 | 51 µs |
| │ └── hard_parse | 2022-10-26 11:46:52.614095 | 146099 µs |
| │ ├── parse | 2022-10-26 11:46:52.614117 | 107 µs |
| │ ├── resolve | 2022-10-26 11:46:52.614278 | 132009 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.615521 | 2939 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.615645 | 282 µs |
| │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.615718 | 105 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.615951 | 2437 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.616760 | 202 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.617050 | 537 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.617471 | 76 µs |
| │ │ ├── close | 2022-10-26 11:46:52.618519 | 204 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.618623 | 53 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.619892 | 2739 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.619939 | 220 µs |
| │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.619975 | 102 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.620180 | 2387 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.620924 | 128 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.621091 | 652 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.621655 | 44 µs |
| │ │ ├── close | 2022-10-26 11:46:52.622682 | 125 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.622745 | 19 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.624044 | 23899 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.624091 | 11634 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.624128 | 25 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.624225 | 11475 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.624235 | 100 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.624398 | 1915 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.626627 | 2494 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.629159 | 4846 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.634040 | 1219 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.635490 | 176 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.635775 | 12087 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.636500 | 9992 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.636578 | 9868 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.636617 | 143 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.636836 | 1990 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.639094 | 2417 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.641548 | 3641 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.645221 | 981 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.646518 | 519 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.646956 | 43 µs |
| │ │ ├── close | 2022-10-26 11:46:52.648193 | 126 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.648253 | 19 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.649571 | 19448 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.649618 | 9188 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.649655 | 27 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.649748 | 9030 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.649758 | 100 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.649920 | 1083 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.651160 | 2832 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.654033 | 3777 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.657849 | 616 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.658636 | 110 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.658862 | 10086 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.659629 | 7986 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.659707 | 7867 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.659717 | 105 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.659892 | 1149 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.661176 | 2772 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.663980 | 2869 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.666882 | 508 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.667639 | 497 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.668055 | 43 µs |
| │ │ ├── close | 2022-10-26 11:46:52.669138 | 149 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.669213 | 27 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.670568 | 22502 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.670620 | 11247 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.670656 | 32 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.670756 | 11090 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.670767 | 109 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.670945 | 1000 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.672098 | 2767 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.674908 | 6113 µs |
| │ │ │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.677206 | 2628 µs |
| │ │ │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.677357 | 319 µs |
| │ │ │ │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.677402 | 145 µs |
| │ │ │ │ │ │ └── open | 2022-10-26 11:46:52.677699 | 2066 µs |
| │ │ │ │ │ │ ├── remote_compile | 2022-10-26 11:46:52.678444 | 168 µs |
| │ │ │ │ │ │ └── remote_execute | 2022-10-26 11:46:52.678657 | 311 µs |
| │ │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.678888 | 41 µs |
| │ │ │ │ │ └── close | 2022-10-26 11:46:52.679861 | 179 µs |
| │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.679950 | 25 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.681048 | 526 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.681716 | 96 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.681919 | 11058 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.682662 | 9133 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.682735 | 9019 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.682742 | 136 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.682943 | 1074 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.684146 | 2685 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.686864 | 4194 µs |
| │ │ │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.688865 | 904 µs |
| │ │ │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.689027 | 390 µs |
| │ │ │ │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.689108 | 192 µs |
| │ │ │ │ │ │ └── open | 2022-10-26 11:46:52.689445 | 168 µs |
| │ │ │ │ │ └── close | 2022-10-26 11:46:52.689805 | 299 µs |
| │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.689964 | 88 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.691084 | 488 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.691820 | 340 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.692084 | 39 µs |
| │ │ ├── close | 2022-10-26 11:46:52.693118 | 205 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.693211 | 32 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.695156 | 18349 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.695215 | 9617 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.695269 | 40 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.695417 | 9379 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.695433 | 159 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.695681 | 1460 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.697324 | 3998 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.701376 | 2260 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.703690 | 700 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.704598 | 150 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.704905 | 8513 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.705840 | 6364 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.705922 | 6240 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.705928 | 126 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.706124 | 1081 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.707328 | 2646 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.710011 | 1450 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.711503 | 482 µs |
| │ │ │ ├── remote_execute | 2022-10-26 11:46:52.712229 | 370 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.712513 | 41 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.720638 | 150 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.720836 | 414 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.721161 | 43 µs |
| │ │ ├── close | 2022-10-26 11:46:52.713562 | 200 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.713655 | 32 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.715620 | 15055 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.715684 | 8245 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.715735 | 36 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.715881 | 8012 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.715898 | 117 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.716115 | 1100 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.717376 | 1819 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.719248 | 3673 µs |
| │ │ │ │ │ ├── remote_compile | 2022-10-26 11:46:52.853181 | 447 µs |
| │ │ │ │ │ ├── remote_execute | 2022-10-26 11:46:52.853697 | 407 µs |
| │ │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.853994 | 70 µs |
| │ │ │ │ │ ├── remote_compile | 2022-10-26 11:46:53.228326 | 205 µs |
| │ │ │ │ │ ├── remote_execute | 2022-10-26 11:46:53.228595 | 472 µs |
| │ │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:53.228952 | 60 µs |
| │ │ │ │ │ ├── remote_compile | 2022-10-26 11:46:54.216432 | 160 µs |
| │ │ │ │ │ └── remote_execute | 2022-10-26 11:46:54.216640 | 376 µs |
| │ │ │ │ │ └── end_transaction | 2022-10-26 11:46:54.216933 | 44 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.722974 | 581 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.723712 | 131 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.723999 | 6591 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.724835 | 4544 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.724915 | 4422 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.724922 | 93 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.725082 | 893 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.726088 | 1284 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.727406 | 1354 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.728800 | 372 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.729404 | 355 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.729671 | 45 µs |
| │ │ ├── close | 2022-10-26 11:46:52.730725 | 197 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.730817 | 32 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.732883 | 12650 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.732949 | 6144 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.733002 | 42 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.733159 | 5897 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.733178 | 152 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.733430 | 1070 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.734626 | 1537 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.736216 | 2000 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.738270 | 457 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.738860 | 148 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.739164 | 6304 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.739976 | 4345 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.740053 | 4223 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.740059 | 121 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.740248 | 840 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.741177 | 1181 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.742392 | 1323 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.743748 | 329 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.744341 | 354 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.744613 | 44 µs |
| │ │ └── close | 2022-10-26 11:46:52.745569 | 134 µs |
| │ │ └── end_transaction | 2022-10-26 11:46:52.745638 | 20 µs |
| │ ├── rewrite | 2022-10-26 11:46:52.746370 | 837 µs |
| │ ├── optimize | 2022-10-26 11:46:52.747238 | 12473 µs |
| │ │ ├── inner_execute_read | 2022-10-26 11:46:52.748664 | 9942 µs |
| │ │ │ ├── sql_compile | 2022-10-26 11:46:52.748713 | 4070 µs |
| │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.748750 | 29 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.748862 | 3900 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.748873 | 125 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.749060 | 756 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.749919 | 988 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.750944 | 1197 µs |
| │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.752178 | 328 µs |
| │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.752635 | 94 µs |
| │ │ │ └── open | 2022-10-26 11:46:52.752805 | 5731 µs |
| │ │ │ ├── remote_compile | 2022-10-26 11:46:52.753552 | 3821 µs |
| │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.753623 | 3709 µs |
| │ │ │ │ ├── parse | 2022-10-26 11:46:52.753630 | 121 µs |
| │ │ │ │ ├── resolve | 2022-10-26 11:46:52.753824 | 850 µs |
| │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.754776 | 1040 µs |
| │ │ │ │ ├── optimize | 2022-10-26 11:46:52.755851 | 987 µs |
| │ │ │ │ └── code_generate | 2022-10-26 11:46:52.756870 | 313 µs |
| │ │ │ └── remote_execute | 2022-10-26 11:46:52.757398 | 346 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.757662 | 43 µs |
| │ │ └── close | 2022-10-26 11:46:52.758639 | 117 µs |
| │ │ └── end_transaction | 2022-10-26 11:46:52.758692 | 19 µs |
| │ ├── code_generate | 2022-10-26 11:46:52.759737 | 278 µs |
| │ └── pc_add_plan | 2022-10-26 11:46:52.760084 | 84 µs |
| └── sql_execute | 2022-10-26 11:46:52.760238 | 66621 µs |
| ├── open | 2022-10-26 11:46:52.760264 | 66344 µs |
| │ ├── remote_compile | 2022-10-26 11:46:52.761033 | 64307 µs |
| │ │ └── hard_parse | 2022-10-26 11:46:52.761098 | 64198 µs |
| │ │ ├── parse | 2022-10-26 11:46:52.761104 | 59 µs |
| │ │ ├── resolve | 2022-10-26 11:46:52.761225 | 56111 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.762547 | 706 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.762643 | 245 µs |
| │ │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.762682 | 105 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.762911 | 109 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.763352 | 222 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.763478 | 47 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.764783 | 784 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.764830 | 215 µs |
| │ │ │ │ │ └── pc_get_plan | 2022-10-26 11:46:52.764868 | 93 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.765068 | 125 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.765619 | 236 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.765762 | 46 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.767071 | 10176 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.767157 | 9610 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.767194 | 26 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.767290 | 9439 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.767335 | 101 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.767505 | 1756 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.769548 | 2212 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.771797 | 3535 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.775369 | 923 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.776525 | 157 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.776834 | 126 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.777503 | 228 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.777635 | 49 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.778990 | 8769 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.779038 | 8288 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.779075 | 29 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.779173 | 8126 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.779184 | 105 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.779352 | 1037 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.780577 | 2782 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.783396 | 3065 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.786506 | 539 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.787164 | 103 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.787384 | 124 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.787922 | 233 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.788060 | 47 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.789477 | 7048 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.789526 | 6664 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.789564 | 28 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.789664 | 6504 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.789674 | 135 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.789877 | 1090 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.791119 | 2785 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.793948 | 1450 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.795436 | 466 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.796035 | 100 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.796245 | 108 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.796567 | 214 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.796686 | 47 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.798061 | 6324 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.798110 | 5953 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.798148 | 30 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.798248 | 5783 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.798258 | 108 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.798428 | 971 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.799532 | 2538 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.802110 | 1243 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.803391 | 411 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.803889 | 101 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.804118 | 110 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.804425 | 215 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.804547 | 47 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.805937 | 4622 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.805986 | 4252 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.806024 | 26 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.806149 | 4063 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.806160 | 86 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.806309 | 742 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.807185 | 1188 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.808411 | 1184 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.809633 | 368 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.810083 | 97 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.810292 | 107 µs |
| │ │ │ ├── close | 2022-10-26 11:46:52.810600 | 219 µs |
| │ │ │ │ └── end_transaction | 2022-10-26 11:46:52.810717 | 47 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.812079 | 4382 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.812125 | 3996 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.812182 | 29 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.812298 | 3798 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.812309 | 105 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.812484 | 706 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.813279 | 1045 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.814363 | 1202 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.815603 | 305 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.815965 | 100 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.816176 | 129 µs |
| │ │ │ └── close | 2022-10-26 11:46:52.816503 | 213 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.816620 | 47 µs |
| │ │ ├── rewrite | 2022-10-26 11:46:52.817417 | 826 µs |
| │ │ ├── optimize | 2022-10-26 11:46:52.818276 | 6566 µs |
| │ │ │ ├── inner_execute_read | 2022-10-26 11:46:52.819735 | 4225 µs |
| │ │ │ │ ├── sql_compile | 2022-10-26 11:46:52.819786 | 3892 µs |
| │ │ │ │ │ ├── pc_get_plan | 2022-10-26 11:46:52.819824 | 30 µs |
| │ │ │ │ │ └── hard_parse | 2022-10-26 11:46:52.819933 | 3720 µs |
| │ │ │ │ │ ├── parse | 2022-10-26 11:46:52.819943 | 128 µs |
| │ │ │ │ │ ├── resolve | 2022-10-26 11:46:52.820161 | 793 µs |
| │ │ │ │ │ ├── rewrite | 2022-10-26 11:46:52.821057 | 1052 µs |
| │ │ │ │ │ ├── optimize | 2022-10-26 11:46:52.822148 | 958 µs |
| │ │ │ │ │ ├── code_generate | 2022-10-26 11:46:52.823143 | 309 µs |
| │ │ │ │ │ └── pc_add_plan | 2022-10-26 11:46:52.823523 | 97 µs |
| │ │ │ │ └── open | 2022-10-26 11:46:52.823700 | 103 µs |
| │ │ │ └── close | 2022-10-26 11:46:52.823999 | 214 µs |
| │ │ │ └── end_transaction | 2022-10-26 11:46:52.824103 | 46 µs |
| │ │ └── code_generate | 2022-10-26 11:46:52.824869 | 273 µs |
| │ ├── remote_execute | 2022-10-26 11:46:52.825363 | 418 µs |
| │ │ └── end_transaction | 2022-10-26 11:46:52.825698 | 43 µs |
| │ ├── remote_compile | 2022-10-26 11:46:53.083805 | 140 µs |
| │ ├── remote_execute | 2022-10-26 11:46:53.083992 | 414 µs |
| │ │ └── end_transaction | 2022-10-26 11:46:53.084319 | 47 µs |
| │ ├── remote_compile | 2022-10-26 11:46:53.710170 | 154 µs |
| │ └── remote_execute | 2022-10-26 11:46:53.710384 | 394 µs |
| │ └── end_transaction | 2022-10-26 11:46:53.710685 | 43 µs |
| ├── response_result | 2022-10-26 11:46:52.826662 | 66 µs |
| └── close | 2022-10-26 11:46:52.826753 | 90 µs |
| └── end_transaction | 2022-10-26 11:46:52.826790 | 15 µs |
+-----------------------------------------------------------------------------------+----------------------------+------------+
333 rows in set 



