ApsaraDB for ClickHouse:Query log analysis

Quick reference

Prerequisites

Before you begin, confirm that query logging is enabled.

By default, query logging is enabled for ApsaraDB for ClickHouse. To confirm:

SHOW settings like 'log_queries';

If the result is 1, query logging is enabled. If the result is 0, run the following statement to enable it:

SET GLOBAL ON CLUSTER default log_queries = 1;

Usage notes

• Query logs may contain sensitive information. Manage access to the system.query_log table accordingly.

• Regularly clean up and archive query logs to avoid excessive log accumulation.

• By default, the query_log table has a time-to-live (TTL) of 15 days. Logs older than 15 days are automatically deleted.

• To reduce disk space usage, adjust the TTL on the Parameter Configuration page in the ApsaraDB for ClickHouse console. Set the TTL to at least 7 days to retain enough history for troubleshooting. For details, see Configure parameters in the config.xml file.

How it works

All queries in this topic filter out QueryStart events (type != 'QueryStart') so each query appears once in the results, with its final status.

Because each node stores only its own query log data, all queries use clusterAllReplicas('default', system.query_log) to aggregate results across all nodes. Use substring(hostname(), 38, 8) to filter results by a specific node name.

To find node names, run:

SELECT * FROM system.clusters;

Or check the Cluster Monitoring tab in the ApsaraDB for ClickHouse console. For details, see View cluster monitoring information.

The examples in this topic use s-2-r-0 as the node name. Replace it with your actual node name.

View queries with errors

Use this query to identify failed queries in a given time window. Error logs help you:

• Pinpoint the root cause of issues directly from the exception field

• Detect repeated failures that indicate systemic problems

• Identify potential security issues such as SQL injection or unauthorized access attempts

Query template

SELECT
    written_rows,
    written_bytes,
    query_duration_ms,
    event_time,
    exception
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time >= '<startTime>'
  AND event_time <= '<endTime>'
  AND lowerUTF8(query) LIKE '%insert into sdk_event_record_local%'
  AND type != 'QueryStart'
  AND exception_code != 0
  [AND substring(hostname(), 38, 8) = '<nodeName>']
ORDER BY event_time DESC
[LIMIT <x>]

Parameters

Example

View error logs on the s-2-r-0 node between 22:00:00 and 23:00:00 on November 22, 2021, returning the most recent 30 results:

SELECT
    written_rows,
    written_bytes,
    query_duration_ms,
    event_time,
    exception
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time >= '2021-11-22 22:00:00'
  AND event_time <= '2021-11-22 23:00:00'
  AND lowerUTF8(query) LIKE '%insert into sdk_event_record_local%'
  AND type != 'QueryStart'
  AND exception_code != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
ORDER BY event_time DESC
LIMIT 30

Find frequently executed queries

Identify non-write queries that exceed a minimum execution count in a time window. Results are sorted by average duration, making it easy to spot high-frequency slow queries.

Query template

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE event_time > toDateTime('<startTime>')
      AND event_time < toDateTime('<endTime>')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = '<nodeName>'
    GROUP BY SQL
    ORDER BY avgTime DESC
)
WHERE queryNum > <queryNum>
[LIMIT <x>]

Parameters

Example

Find non-write queries executed more than 1,000 times on the s-2-r-0 node between 12:00:00 and 17:00:00 on September 23, 2022:

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE event_time > toDateTime('2022-09-23 12:00:00')
      AND event_time < toDateTime('2022-09-23 17:00:00')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = 's-2-r-0'
    GROUP BY SQL
    ORDER BY avgTime DESC
)
WHERE queryNum > 1000
LIMIT 50

View execution statistics by time interval

Aggregate query count and average duration, grouped by hour or minute. Use these queries to detect traffic spikes and latency regressions over time.

-- View execution statistics by hour
SELECT
    toHour(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('<startTime>')
  AND event_time < toDateTime('<endTime>')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY t
[LIMIT <x>]

-- View execution statistics by hour
SELECT
    toHour(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('2022-09-23 08:00:00')
  AND event_time < toDateTime('2022-09-23 17:00:00')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY t
LIMIT 50

-- View execution statistics by minute
SELECT
    toMinute(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('<startTime>')
  AND event_time < toDateTime('<endTime>')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY t
[LIMIT <x>]

-- View execution statistics by minute
SELECT
    toMinute(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('2022-09-23 12:00:00')
  AND event_time < toDateTime('2022-09-23 13:00:00')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY t
LIMIT 50

Count JOIN queries

View the volume and average duration of JOIN queries in a given time window. Use this query to assess the impact of JOIN operations on cluster performance.

Query template

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE query LIKE '%JOIN%'
      AND read_rows != 0
      AND event_time > toDateTime('<startTime>')
      AND event_time < toDateTime('<endTime>')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = '<nodeName>'
    GROUP BY SQL
    ORDER BY queryNum DESC
)

Parameters

Example

Count JOIN queries on the s-2-r-0 node between 12:00:00 and 15:00:00 on June 25, 2024:

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE query LIKE '%JOIN%'
      AND read_rows != 0
      AND event_time > toDateTime('2024-06-25 12:00:00')
      AND event_time < toDateTime('2024-06-25 15:00:00')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = 's-2-r-0'
    GROUP BY SQL
    ORDER BY queryNum DESC
)

Rank users by query count

View which users executed the most non-write queries yesterday, along with total rows and bytes read.

Query template

SELECT
    user,
    count(1) AS query_times,
    sum(read_bytes) AS query_bytes,
    sum(read_rows) AS query_rows
FROM clusterAllReplicas('default', system.query_log)
WHERE event_date = yesterday()
  AND is_initial_query = 1
  AND query NOT LIKE 'INSERT INTO%'
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY user
ORDER BY query_times DESC
[LIMIT <x>]

Parameters

Example

View the top 10 users by non-write query count on the s-2-r-0 node for yesterday:

SELECT
    user,
    count(1) AS query_times,
    sum(read_bytes) AS query_bytes,
    sum(read_rows) AS query_rows
FROM clusterAllReplicas('default', system.query_log)
WHERE event_date = yesterday()
  AND is_initial_query = 1
  AND query NOT LIKE 'INSERT INTO%'
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY user
ORDER BY query_times DESC
LIMIT 10

What's next

• Configure parameters in the config.xml file — adjust the query_log TTL and other logging parameters

• View cluster monitoring information — check node names and cluster health metrics