Log analysis

Updated at:

PolarDB-X supports the SQL audit and analysis feature, which uses Log Service to provide powerful log analysis capabilities. This topic describes example query statements for analyzing SQL logs in common scenarios.

Prerequisites

The SQL audit and analysis feature is enabled.

Usage notes

  • The audit logs for all PolarDB-X databases in the same region are written to the same Logstore in Log Service. Therefore, the search box on the SQL audit and analysis page for PolarDB-X automatically includes a filter condition for __topic__. This ensures that your search results contain only SQL logs from PolarDB-X databases in the same region. You must append all query statements provided in this document to the existing __topic__ filter condition.

    For example, in the following figure, part 1 is the default filter condition, and part 2 is the appended query statement.

  • On the Raw Log tab, you can click the value of a field to automatically add a corresponding query condition to the search box.

    For example, find a field such as sql_type and click its value, such as Delete, to view all SQL statements of the Delete type.

Find specific SQL

You can use the following statements to quickly locate problematic SQL.

  • Keyword search

    For example, you can use the following command to query for SQL statements that contain the keyword 200003:

    and sql: 200003
  • Field search

    Based on preset index fields, the SQL audit feature of PolarDB-X also supports searches by field. For example, you can use the following command to query for DROP-type SQL:

    and sql_type:Drop
  • Multi-condition search

    You can use keywords such as and or or to perform searches with multiple conditions. For example, you can use the following command to query for all DELETE statements performed on the row where id=200003:

    and sql: 200003 and sql_type: Delete
  • Numeric comparison search

    The index fields affect_rows and response_time are numeric types and support comparison operators. For example, you can use the following command to query for DROP statements where the response_time is greater than 5 ms:

    and response_time > 5 and sql_type: Drop

    You can also use the following statement to find SQL statements that deleted more than 100 rows:

    and affect_rows > 100 and sql_type: Delete

SQL execution analysis

You can use the following statements to view SQL execution status.

  • SQL execution failure rate

    Use the following statement to query the failure rate of SQL executions:

    | SELECT sum(case when fail = 1 then 1 else 0 end) * 1.0 / count(1) as fail_ratio

    Query result:

    Note

    If your application is sensitive to SQL error rates, click Save as Alert in the upper-right corner of the query results page to create a custom alert.

  • Total rows returned

    Use the following statement to query the total number of rows returned by SELECT statements:

    and sql_type: Select | SELECT sum(affect_rows)
  • Distribution of SQL types

    Use the following statement to view the distribution of SQL statement types:

    | SELECT  sql_type, count(sql) as times GROUP BY sql_type
  • Unique client IP distribution

    Use the following statement to view the distribution of unique client IP addresses for each user:

    | SELECT  user, client_ip, count(sql) as times GROUP BY user, client_ip

SQL performance analysis

You can use the following statements to analyze SQL performance.

  • Average SELECT response time

    Use the following statement to query the average execution time of SELECT statements:

    and sql_type: Select | SELECT avg(response_time)
  • Distribution of SQL execution times

    Use the following statement to view the distribution of SQL execution times:

    and response_time > 0 | select   case  when response_time <= 10 then '<=10ms'  when response_time > 10 and response_time <= 100 then '10-100ms'  when response_time > 100 and response_time <= 1000 then '100ms-1s'  when response_time > 1000 and response_time <= 10000  then '1s-10s'  when response_time > 10000 and response_time <= 60000  then '10s-1min'  else '>1min' end as latency_type,  count(1) as cnt group by latency_type order by latency_type DESC
    Note

    The preceding query categorizes the SQL execution time into four ranges based on the value of response_time: less than or equal to 10 ms, greater than 10 ms and less than or equal to 100 ms, greater than 100 ms and less than or equal to 1 s, and greater than 1 s and less than or equal to 10 s. You can also customize the time ranges for response_time to obtain more granular results.

  • Top 50 slow SQL statements

    Use the following statement to query the top 50 slow SQL statements:

    | SELECT date_format(from_unixtime(__time__), '%m/%d %H:%i:%s') as time, user, client_ip, client_port, sql_type, affect_rows, response_time, sql ORDER BY  response_time desc LIMIT 50

    The results include details such as the execution time, username, client IP address, client port, SQL type, number of affected rows, response time, and the specific SQL statement.

  • Top 10 high-cost SQL templates

    SQL statements are often generated from templates. Use the following statement to identify high-cost SQL templates by their template ID:

    | SELECT sql_code as "Template ID", round(total_time * 1.0 /sum(total_time) over() * 100, 2) as "Execution duration ratio (%)" ,execute_times as "Number of queries", round(avg_time) as "Average execution duration",round(avg_rows) as "Average affected rows", CASE WHEN length(sql) > 200 THEN  concat(substr(sql, 1, 200), '......') ELSE trim(lpad(sql, 200, ' ')) end as "Sample SQL" FROM  (SELECT sql_code, count(1) as execute_times, sum(response_time) as total_time, avg(response_time) as avg_time, avg(affect_rows) as avg_rows, arbitrary(sql) as sql FROM log GROUP BY sql_code) ORDER BY "Execution duration ratio (%)" desc limit 10

    The results include the SQL template ID, the template's percentage of total execution time, number of executions, average execution time, average number of affected rows, and a sample SQL statement.

    Note

    The query results above are sorted by Total Time (%). You can also sort the results by Average Execution Time or Executions to troubleshoot issues.

  • Transaction performance analysis

    For SQL statements within the same transaction, the trace_id field has a common prefix and a suffix of '-' + a sequence number, while the trace_id for a non-transactional SQL statement does not contain '-'. Therefore, you can use the following command to analyze the performance of transactional SQL statements.

    Note

    Transaction analysis involves prefix matching, which can be less efficient than other types of queries.

    • Average transaction duration

      Use the following statement to query the average execution duration of transactions:

      | SELECT sum(response_time) / COUNT(DISTINCT substr(trace_id, 1, strpos(trace_id, '-') - 1)) WHERE strpos(trace_id, '-') > 0
    • Top 10 slow transactions

      Use the following statement to find the 10 transactions with the longest execution times:

      | SELECT substr(trace_id, 1, strpos(trace_id, '-') - 1) as "Transaction ID" , sum(response_time) as "Execution duration" WHERE strpos(trace_id, '-') > 0 GROUP BY substr(trace_id, 1, strpos(trace_id, '-') - 1) ORDER BY "Execution duration" DESC LIMIT 10

      Then, use the transaction ID to search for all SQL statements within the transaction and analyze the root cause of the slowness:

       and trace_id: db3226a20402000*
    • Top 10 large-batch transactions

      Use the following statement to sort transactions by the number of affected rows and find transactions that involve large-batch operations:

      | SELECT substr(trace_id, 1, strpos(trace_id, '-') - 1) as "Transaction ID" , sum(affect_rows) as "Affected rows" WHERE strpos(trace_id, '-') > 0 GROUP BY substr(trace_id, 1, strpos(trace_id, '-') - 1) ORDER BY "Affected rows" DESC LIMIT 10

SQL security analysis

You can use the following statements to analyze SQL security.

  • Distribution of failed SQL types

    Use the following statement to view the distribution of failed SQL statements by type:

    and fail > 0 | select sql_type, count(1) as "Number of failures" group by sql_type
  • High-risk SQL list

    In PolarDB-X, a high-risk SQL statement is typically a DROP or TRUNCATE statement. You can also define your own criteria for what constitutes high-risk SQL.

    Use the following statement to find all DROP or TRUNCATE statements:

    and sql_type: Drop OR sql_type: Truncate
  • Large-batch delete statements

    Use the following statement to find DELETE statements that affected a large number of rows:

    and affect_rows > 100 and sql_type: Delete | SELECT date_format(from_unixtime(__time__), '%m/%d %H:%i:%s') as time, user, client_ip, client_port, affect_rows, sql ORDER BY  affect_rows desc LIMIT 50