Show Trace

The Show Trace feature can interactively provide the statistics and distribution of time consumed in different phases of the last executed SQL request, thereby facilitating bottleneck analysis and problem demarcation. This topic describes how to use the Show Trace feature.

Background

Database issues related to time consumption are difficult to locate and troubleshoot. These issues involve many components, such as client applications, drivers, load balancers, proxies, and databases. OceanBase Database V4.x provides the end-to-end tracing feature to streamline the interactions between these components. This allows you to view the time consumption of each SQL statement, analyze issues, and identify bottlenecks.

Supported versions of the components

• OceanBase Database: V4.2.0 and later

• OceanBase Database Proxy (ODP): V4.2.0 and later

• Java Database Connectivity (JDBC): V2.4.3 and later

• OceanBase Client (OBClient): V2.2.3 and later

• OceanBase Cloud Platform (OCP): V4.0.3 and later

Considerations

The Show Trace feature is released with OceanBase Database V4.2.0 and uses the OceanBase 2.0 protocol. Pay attention to the following points about this feature:

• When you use the end-to-end tracing feature along with components of the supported versions, you can use a session-level switch to turn on session-level Show Trace capabilities. Then, the information about each SQL interaction with the driver, OceanBase Database Proxy (ODP), and OceanBase Database will be recorded. After an SQL request is executed, you can run the show trace command to query the diagnostic information about the SQL execution record.

• The diagnostic information generated by the Show Trace feature is exchanged between the driver, ODP, and OceanBase Database. You can view the complete path record.

• By default, the Show Trace feature is disabled. The protocol-based transmission of the diagnostic information incurs extra overhead in parsing, transmission, and record processing. This degrades the performance. Therefore, by default, components do not record Show Trace information.

• Like the end-to-end tracing feature, the Show Trace feature uses a protocol and is implemented based on interactions. If the version of a component is incorrect or Show Trace is disabled, the results of interactions between the upstream and downstream components are affected. The following scenarios may exist.

  • If the Show Trace feature is not supported or is disabled in OceanBase Database, the overall Show Trace capabilities are unavailable.

  • If Show Trace is supported and enabled in OceanBase Database but the driver and ODP do not support Show Trace, you can run the show trace command to obtain the interaction information about the last SQL request. However, you can obtain only the information about interactions in OceanBase Database.

  • If Show Trace is supported and enabled in OceanBase Database and ODP but the driver does not support Show Trace, you can run the show trace command to obtain the interaction information about the last SQL request. However, you can obtain only the information about interactions in ODP and OceanBase Database.

  • If Show Trace is supported and enabled in the driver, ODP, and OceanBase Database, you can run the show trace command in the session to obtain complete interaction information about the last SQL request at the database layer.

Procedure

Step 1: Configure the components

To use the Show Trace feature, make sure that the versions of the components are correct and that the OceanBase 2.0 protocol and the end-to-end tracing feature are enabled.

1. In ODP, you can use the enable_ob_protocol_v2_with_client and enable_ob_protocol_v2 parameters to respectively control whether to enable the OceanBase 2.0 protocol between ODP and the driver and between ODP and OceanBase Database. The default value of enable_ob_protocol_v2_with_client is false and that of enable_ob_protocol_v2 is true. You can configure ODP in the following ways:

   • Method 1: Perform the configuration by using the -o option when the ODP process starts.

     cd /opt/taobao/install/obproxy
     ./bin/obproxy -o enable_ob_protocol_v2_with_client=true,enable_ob_protocol_v2=true
     

   • Method 2: Log on to the proxysys tenant as the root user and execute the following SQL statement:

     obclient> alter proxyconfig set enable_ob_protocol_v2_with_client=true;
     obclient> alter proxyconfig set enable_ob_protocol_v2=true;
     

2. Configure OBClient by using environment variables.

   1. Run the following command to enable the OceanBase 2.0 protocol. The value 0 specifies to disable the protocol, and 1 specifies to enable the protocol.

      export ENABLE_PROTOCOL_OB20=1;
      

   2. Run the following command to enable the end-to-end tracing feature. The value 0 specifies to disable the feature, and 1 specifies to enable the feature.

      export ENABLE_TRACE=1;
      

3. Add enableFullLinkTrace=true or useOceanBaseProtocolV20=true&enableFullLinkTrace=true to the JDBC URL to enable the end-to-end tracing feature for JDBC.

Step 2: Enable the Show Trace feature and execute the target SQL query

1. If Show Trace is supported in all required components and the OceanBase 2.0 protocol is enabled, you can enable the end-to-end tracing feature. Then, connect to your OceanBase database by using a client and run the following command to enable session-level Show Trace:

   obclient> set ob_enable_show_trace='on';
   

2. Execute the target SQL request, which is show tables; in the following example.

   obclient> show tables;
   +----------------------------+
   | Tables_in_test             |
   +----------------------------+
   | t                          |
   | t1                         |
   | t2                         |
   +----------------------------+
   3 rows in set
   

Step 3: Use the Show Trace feature

You can run the show trace; command to obtain the result set or run the show trace format='json'; command to obtain the result set in JSON format.

• Run the show trace; command to obtain the result set.

  • Example 1: If ODP and the OBServer node are deployed on different servers, run the show trace; command to view the execution records of this SQL request. Sample result:

    obclient> show trace;
    +-----------------------------------------------+----------------------------+------------+
    | Operation                                     | StartTime                  | ElapseTime |
    +-----------------------------------------------+----------------------------+------------+
    | obclient                                      | 2023-06-30 15:29:31.402635 | 43.410 ms  |
    | └── ob_proxy                                  | 2023-06-30 15:29:31.202131 | 43.210 ms  |
    |     ├── ob_proxy_partition_location_lookup    | 2023-06-30 15:29:31.202222 | 0.015 ms   |
    |     └── ob_proxy_server_process_req           | 2023-06-30 15:29:31.202662 | 42.023 ms  |
    |         └── com_query_process                 | 2023-06-30 15:29:31.222125 | 2.889 ms   |
    |             └── mpquery_single_stmt           | 2023-06-30 15:29:31.222142 | 2.862 ms   |
    |                 ├── sql_compile               | 2023-06-30 15:29:31.222153 | 2.406 ms   |
    |                 │   ├── pc_get_plan           | 2023-06-30 15:29:31.222157 | 0.006 ms   |
    |                 │   └── hard_parse            | 2023-06-30 15:29:31.222225 | 2.308 ms   |
    |                 │       ├── parse             | 2023-06-30 15:29:31.222233 | 0.022 ms   |
    |                 │       ├── resolve           | 2023-06-30 15:29:31.222278 | 0.491 ms   |
    |                 │       ├── rewrite           | 2023-06-30 15:29:31.222829 | 0.872 ms   |
    |                 │       ├── optimize          | 2023-06-30 15:29:31.223723 | 0.544 ms   |
    |                 │       └── code_generate     | 2023-06-30 15:29:31.224283 | 0.129 ms   |
    |                 └── sql_execute               | 2023-06-30 15:29:31.224569 | 0.347 ms   |
    |                     ├── open                  | 2023-06-30 15:29:31.224570 | 0.023 ms   |
    |                     ├── response_result       | 2023-06-30 15:29:31.224601 | 0.233 ms   |
    |                     │   └── do_local_das_task | 2023-06-30 15:29:31.224619 | 0.093 ms   |
    |                     └── close                 | 2023-06-30 15:29:31.224843 | 0.057 ms   |
    |                         ├── close_das_task    | 2023-06-30 15:29:31.224846 | 0.005 ms   |
    |                         └── end_transaction   | 2023-06-30 15:29:31.224889 | 0.002 ms   |
    +-----------------------------------------------+----------------------------+------------+
    20 rows in set
    

  • Example 2: If ODP and the OBServer node are deployed on the same server, run the show trace; command to view the execution records of this SQL request. Sample result:

    obclient> show trace;
    +-----------------------------------------------+----------------------------+------------+
    | Operation                                     | StartTime                  | ElapseTime |
    +-----------------------------------------------+----------------------------+------------+
    | obclient                                      | 2023-06-30 15:30:59.812735 | 2.957 ms   |
    | └── ob_proxy                                  | 2023-06-30 15:30:59.503655 | 2.648 ms   |
    |     ├── ob_proxy_partition_location_lookup    | 2023-06-30 15:30:59.503658 | 0.017 ms   |
    |     └── ob_proxy_server_process_req           | 2023-06-30 15:30:59.503757 | 2.466 ms   |
    |         └── com_query_process                 | 2023-06-30 15:30:59.503856 | 2.248 ms   |
    |             └── mpquery_single_stmt           | 2023-06-30 15:30:59.503861 | 2.236 ms   |
    |                 ├── sql_compile               | 2023-06-30 15:30:59.503869 | 1.850 ms   |
    |                 │   ├── pc_get_plan           | 2023-06-30 15:30:59.503871 | 0.003 ms   |
    |                 │   └── hard_parse            | 2023-06-30 15:30:59.503920 | 1.788 ms   |
    |                 │       ├── parse             | 2023-06-30 15:30:59.503927 | 0.013 ms   |
    |                 │       ├── resolve           | 2023-06-30 15:30:59.503955 | 0.387 ms   |
    |                 │       ├── rewrite           | 2023-06-30 15:30:59.504383 | 0.657 ms   |
    |                 │       ├── optimize          | 2023-06-30 15:30:59.505058 | 0.419 ms   |
    |                 │       └── code_generate     | 2023-06-30 15:30:59.505512 | 0.105 ms   |
    |                 └── sql_execute               | 2023-06-30 15:30:59.505729 | 0.296 ms   |
    |                     ├── open                  | 2023-06-30 15:30:59.505729 | 0.016 ms   |
    |                     ├── response_result       | 2023-06-30 15:30:59.505753 | 0.216 ms   |
    |                     │   └── do_local_das_task | 2023-06-30 15:30:59.505766 | 0.095 ms   |
    |                     └── close                 | 2023-06-30 15:30:59.505976 | 0.038 ms   |
    |                         ├── close_das_task    | 2023-06-30 15:30:59.505977 | 0.005 ms   |
    |                         └── end_transaction   | 2023-06-30 15:30:59.506006 | 0.002 ms   |
    +-----------------------------------------------+----------------------------+------------+
    20 rows in set
    

  You can first demarcate the issue based on the result. Specifically, you can analyze the time consumption at the following timestamps to quickly learn about the overall execution time in the database to facilitate further analysis and optimization.

  • The driver has only one timestamp named oceanbase_jdbc or obclient, respectively corresponding to JDBC and OBClient. This timestamp records the duration from the time when the client sends an SQL request to the time when the client receives a response.

  • ob_proxy is the start timestamp of ODP. It records the duration from the time when ODP receives an SQL request to the time when ODP sends a response to the client. The time difference between obclient and ob_proxy approximates the time overhead in network transmission plus the time for packet receiving and sending between the driver and ODP. You can find the difference in Example 1 and Example 2.

  • ob_proxy_server_process_req is the duration from the time when an SQL request is sent to the time when the first response is received from the OBServer node. It equals the value of the request processing time on the OBServer node plus the network transmission time for sending the response.

  • com_query_process is the total timestamp of OceanBase Database. It records the duration from the time when the OBServer node receives an SQL request to the time when the OBServer node returns a response.

• Run the show trace format='json'; command to obtain the result set in JSON format.

  Run the show trace format = 'json'; command to obtain the result set in JSON format. You can format the result set to facilitate collection and analysis, as shown in the following figure.

  

You can repeatedly run the show trace; or show trace format='json'; command to view the result in real time.

Step 4: Disable the Show Trace feature

After analysis, run the following command to disable the session-level Show Trace feature to avoid affecting the performance.

obclient> set ob_enable_show_trace='off';