The end-to-end tracing 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 node, 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 are as follows:
#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 are as follows:
#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
Spans are described as follows:
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 are described as follows:
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 operator 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 operator 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 end-to-end tracing 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. For more information, see End-to-end tracing. Here is an example:
+-------------------------------------------+----------------------------+------------+
| Operation | StartTime | ElapseTime |
+-------------------------------------------+----------------------------+------------+
| com_query_process | 2023-03-22 14:30:27.552259 | 0.405 ms |
| └── mpquery_single_stmt | 2023-03-22 14:30:27.552266 | 0.386 ms |
| ├── sql_compile | 2023-03-22 14:30:27.552283 | 0.083 ms |
| │ └── pc_get_plan | 2023-03-22 14:30:27.552286 | 0.025 ms |
| └── sql_execute | 2023-03-22 14:30:27.552379 | 0.242 ms |
| ├── open | 2023-03-22 14:30:27.552380 | 0.024 ms |
| ├── response_result | 2023-03-22 14:30:27.552417 | 0.140 ms |
| │ ├── get_das_id | 2023-03-22 14:30:27.552421 | 0.000 ms |
| │ └── do_local_das_task | 2023-03-22 14:30:27.552435 | 0.049 ms |
| └── close | 2023-03-22 14:30:27.552570 | 0.039 ms |
| ├── close_das_task | 2023-03-22 14:30:27.552571 | 0.012 ms |
| └── end_transaction | 2023-03-22 14:30:27.552596 | 0.003 ms |
+-------------------------------------------+----------------------------+------------+
12 rows in set (0.006 sec)