The end-to-end diagnostics feature of OceanBase Database can record the time consumed in each stage of the connection from a client to an OceanBase Database Proxy (ODP) and then to an OBServer, as well as the trace information related to component diagnostics. The trace log records information by span. Each span records the time consumed in an execution interval or module and related information by using tags. The information helps you understand the internal processing logic of the database and locate problems.
Spans and tags
Spans and tags are defined in the ob_trace_def.h file and are divided into three levels: HIGH (Level 1), MIDDLE (Level 2), and LOW (Level 3). HIGH is the default level. Spans and tags at Level 1 are recorded by default. To record spans and tags at other levels, run the control command to escalate the trace level. Level 2 spans record information for your analysis. Level 3 spans record more details for diagnostics by OceanBase Database developers. If you set the trace level to N, spans and tags at Level N and lower levels are recorded in the trace log.
Span definitions:
#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 definitions:
#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 description:
com_query_entry: the query procedure.mpquery_single_stmt: the access path of a single statement.sql_compile: specifies to compile an SQL statement.pc_get_plan: specifies to obtain an execution plan.hard_parse: specifies to perform hard parsing.parse: specifies to perform soft parsing.resolve: specifies to parse the semantics of a syntax tree and generate a statement.rewrite: specifies to rewrite an SQL statement.optimize: specifies to perform cost-based optimization and generate execution plan logs.code_generate: specifies to generate a physical execution plan based on the execution plan logs.pc_add_plan: specifies to add a generated execution plan to the plan cache.sql_execute: specifies to execute a physical execution plan.open: specifies to open an execution plan.response_result: the plan execution process and results.px_schedule: specifies to divide tasks by parallel execution (PX).px_task: specifies to execute a PX subtask.close: specifies to close an execution plan.cmd_execute: specifies to execute a command.cmd_open: specifies to open a CMD plan.ps_prepare: specifies to create a prepared statement.ps_execute: specifies to execute a prepared statement.ps_close: specifies to close a prepared statement.pl_entry: specifies to process a stored procedure.pl_compile: specifies to compile stored procedure objects.pc_get_pl_object: specifies to obtain stored procedure objects from the plan cache.pc_add_pl_object: specifies to add stored procedure objects to the plan cache.pl_execute: specifies to execute a stored procedure.pl_spi_query: specifies to execute the SPI statement in the stored procedure.pl_spi_prepare: the preprocessing phase of stored procedures.pl_spi_execute: specifies to execute the SPI statement in the stored procedure.inner_prepare: the preprocessing phase of internal SQL statements.inner_execute: the execution phase of internal SQL statements.inner_execute_read: specifies to read an internal SQL statement.inner_execute_write: specifies to write an internal SQL statement.inner_commit: specifies to commit an internal SQL transaction.inner_rollback: specifies to roll back an internal SQL transaction.
Tags
com_query_entrylog_trace_id: the trace ID of the current request in logs.err_code: the error code of the current request.
sql_compilesess_id: the session ID.sql_text: the text of the SQL statement.sql_id: the ID of the SQL statement.hit_plan: indicates that the execution plan hits the plan cache.
px_tasktask_id: the logical ID of the parallel task.dfo_id: the data flow operation ID.sqc_id: the ID of the subquery coordinator.qc_id: the ID of the query coordinator.group_id: the ID of the resource group.
px_scheduledfo_id: the data flow operation ID.used_worker_cnt: the number of PX worker threads in use.qc_id: the ID of the query coordinator.
ps_closeps_id: the ID of the prepared statement.
Examples
You can use procedures in the PL/SQL package DBMS_MONITOR as needed to enable or disable a end-to-end diagnostic trace for an application based on different identifiers and record the trace information into the log files. The sampling frequency determines whether logs are sampled and recorded in the memory. Logs may also be recorded in the trace log file.
Example:
+-----------------------------------------------------------------------------------+----------------------------+------------+
| 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