OBProxy provides a slow-query logging feature. An SQL query or transaction is logged if either of the following two logging thresholds is reached.
| Parameter | Description |
|---|---|
| slow_transaction_time_threshold | The threshold for the duration of the entire lifecycle of a query or transaction. The query or transaction is logged when this threshold is reached. |
| slow_proxy_process_time_threshold | The threshold for the time that OBProxy spends on processing a query or transaction before the query or transaction reaches an OBServer. It includes the time spent on retrieving the information about the cluster, routing, and blacklist. |
| slow_query_time_threshold | The threshold for the period from the moment OBProxy receives an SQL query to the moment OBProxy returns the result to the client. The query is logged when this threshold is reached. |
View and modify parameters of slow queries in OBProxy
Log on to the sys tenant as the root user from OceanBase Client (OBClient).
Execute the following statements to view these parameters:
obclient> SHOW PROXYCONFIG LIKE 'slow_transaction_time_threshold'; obclient> SHOW PROXYCONFIG LIKE 'slow_proxy_process_time_threshold'; obclient> SHOW PROXYCONFIG LIKE 'slow_query_time_threshold';
Modify slow query parameters in OBProxy
Generally, you only need to modify the
slow_transaction_time_thresholdparameter. The default value ofslow_proxy_process_time_thresholdis 2 ms. This value is suitable for most cases. To modify the value of a parameter, see the following examples:obclient> ALTER PROXYCONFIG SET slow_transaction_time_threshold='100ms'; obclient> alter proxyconfig set slow_proxy_process_time_threshold='5ms';
Check slow queries
You can find the SQL statements that take a long time to execute in the slow query log of OBProxy.
You can find the OBProxy log in the following directory: /opt/taobao/install/[obproxy directory]/log. The value of the [obproxy_directory] placeholder may vary with the OBProxy version. In earlier versions, it is obproxy. In the latest version, it is obproxy-[version_number], for example, obproxy-1.5.7.
In the terminal of the host where OBProxy is deployed, enter the preceding directory, and execute the following command to view slow queries:
grep -i 'slow query'
You can use the following command to display the slow queries in a format that is easy to read:
grep -i 'slow query' obproxy.xxx.log | sed "s/, /,\n/g
The following example shows a formatted sample log.
[2020-02-19 15:17:01.072491] WARN [PROXY.SM] update_cmd_stats (ob_mysql_sm.cpp:5673) [103335][Y0-7FF57C8613A0] [lt=10] [dc=0] Slow Query: (client_ip={127.0.0.1:44228}, // The IP address of the client that executes the SQL query.
server_ip={xxx.xxx.xxx.xxx:2881} // The IP address of the OBServer to which the SQL query was routed.
server_trace_id=YB420BA65786-00059E5922A874E6 // The trace ID of the execution process in the target OBServer.
route_type=ROUTE_TYPE_LEADER // The routing policy used by the SQL query.
user_name=root // The username used to connect to the database.
tenant_name=xxx // The name of the tenant to be connected to.
cluster_name=xxx // The OceanBase cluster where the OBServer is deployed.
use_compress_protocol=true // Indicates whether a compression protocol is used during the transmission.
cs_id=365 // The connection ID that is displayed on the logon page of the client. This ID is assigned by OBProxy.
proxy_sessid=7 // The connection ID that OceanBase recorded for a visit from the client
ss_id=10
server_sessid=3221946244 // The connection ID of the SQL query in the target OBServer. This ID is assigned by OBServer.
sm_id=9535
cmd_size_stats={client_request_bytes:31 // The size of the SQL query sent by the client.
server_request_bytes:49 // The size of the SQL query forwarded to the OBServer, in bytes.
server_response_bytes:0 // The size of the data that OBServer forwarded to OBProxy, in bytes.
client_response_bytes:76} // The size of the data that OBProxy forwarded to the client, in bytes.
cmd_time_stats={
client_transaction_idle_time_us=0 // The time interval between the start of the current SQL query and the end of the last SQL query. Unit: us.
client_request_read_time_us=27 // The time spent by OBProxy on reading the request packets from the client socket. Unit: us.
client_request_analyze_time_us=25 // The time spent by OBProxy on analyzing the SQL query sent by the client. Unit: us.
cluster_resource_create_time_us=0 // The time spent by OBProxy on caching cluster resources. OBProxy caches cluster resources only when it accesses the cluster for the first time. Unit: us.
pl_lookup_time_us=16 // The time spent on retrieving the routing table based on the SQL query. Unit: us.
pl_process_time_us=34 // The time spent on processing the routing table. Unit: us.
congestion_control_time_us=5 // The time spent on retrieving the blacklist based on the SQL query. Unit: us.
congestion_process_time_us=0 // The time spent on checking and filtering the blacklist based on the SQL query. Unit: us.
do_observer_open_time_us=198 // The time spent on retrieving the available connections, including the connection time (connect_time), from the target OBServer. Unit: us.
server_connect_time_us=166 // The time spent on creating the connection between the client and the target OBServer. Unit: us.
server_sync_session_variable_time_us=1127 // The time spent on initializing the target connection. The initialization process includes saving the login information (saved_login) and synchronizing the database, system variables, the last insert ID (the ID of the last record you added to your database, represented by last_insert_id), and the transaction start time (start_trans). Unit: us.
server_send_saved_login_time_us=571 // The time spent on saving the login information (saved login) for the target connection. Unit: us.
server_send_use_database_time_us=189 // The time spent on synchronizing the database for the target connection. Unit: us.
server_send_session_variable_time_us=366 // The time spent on synchronizing modified system variables for the target connection. Unit: us.
server_send_all_session_variable_time_us=0 // The time spent on synchronizing all system variables for the target connection. Unit: us.
server_send_last_insert_id_time_us=0 // The time spent on synchronizing the last insert ID (last_insert_id) for the target connection. Unit: us.
server_send_start_trans_time_us=0 // The time spent on synchronizing the transaction start time (start_trans/begin) for the target connection. Unit: us.
build_server_request_time_us=37 // The time spent on creating the request packets to the target OBServer. Unit: us.
plugin_compress_request_time_us=0 // The time spent on compressing the request packets. Unit: us.
prepare_send_request_to_server_time_us=1606 // The time spent from the moment OBProxy received the request from the client to the moment the request is forwarded to an OBServer for execution. The value of this parameter is the sum of the values of the preceding parameters. Unit: us.
server_request_write_time_us=8 // The time spent by OBProxy on sending the request packets to the target server socket. Unit: us.
server_process_request_time_us=381489 // The time that the OBServer spent on executing the SQL query. Unit: us.
server_response_read_time_us=9 // The time that OBProxy spends on reading the response packets from the server socket. Unit: us.
plugin_decompress_response_time_us=13 // The time spent on decompressing the response packets. Unit: us.
server_response_analyze_time_us=10 // The time spent on analyzing the response packets. Unit: us.
ok_packet_trim_time_us=0 // The time spent on trimming the last OK packet in the response packets. Unit: us.
client_response_write_time_us=34 // The time spent by OBProxy on sending the response packets to the client socket. Unit: us.
request_total_time_us=383233} // The total time spent by OBProxy on processing the request. The value of this parameter is the sum of the values of the preceding parameters. Unit: us.
sql=select count(1) from test1) // The SQL query sent by the client.